diff --git a/glance/api/v1/images.py b/glance/api/v1/images.py index acf59ffdf4..dd6ec068b2 100644 --- a/glance/api/v1/images.py +++ b/glance/api/v1/images.py @@ -564,7 +564,7 @@ class Controller(controller.BaseController): image_data, image_size = self._get_from_store(req.context, copy_from) except Exception as e: - upload_utils.safe_kill(req, image_meta['id']) + upload_utils.safe_kill(req, image_meta['id'], 'queued') msg = _("Copy from external source failed: %s") % e LOG.debug(msg) return @@ -573,7 +573,7 @@ class Controller(controller.BaseController): try: req.get_content_type(('application/octet-stream',)) except exception.InvalidContentType: - upload_utils.safe_kill(req, image_meta['id']) + upload_utils.safe_kill(req, image_meta['id'], 'queued') msg = _("Content-Type must be application/octet-stream") LOG.debug(msg) raise HTTPBadRequest(explanation=msg) diff --git a/glance/api/v1/upload_utils.py b/glance/api/v1/upload_utils.py index f8d0f7a330..8fcf76685d 100644 --- a/glance/api/v1/upload_utils.py +++ b/glance/api/v1/upload_utils.py @@ -45,18 +45,23 @@ def initiate_deletion(req, location, id, delayed_delete=False): glance.store.safe_delete_from_backend(req.context, location, id) -def _kill(req, image_id): +def _kill(req, image_id, from_state): """ Marks the image status to `killed`. :param req: The WSGI/Webob Request object :param image_id: Opaque image identifier + :param from_state: Permitted current status for transition to 'killed' """ + # TODO(dosaboy): http://docs.openstack.org/developer/glance/statuses.html + # needs updating to reflect the fact that queued->killed and saving->killed + # are both allowed. registry.update_image_metadata(req.context, image_id, - {'status': 'killed'}) + {'status': 'killed'}, + from_state=from_state) -def safe_kill(req, image_id): +def safe_kill(req, image_id, from_state): """ Mark image killed without raising exceptions if it fails. @@ -65,9 +70,10 @@ def safe_kill(req, image_id): :param req: The WSGI/Webob Request object :param image_id: Opaque image identifier + :param from_state: Permitted current status for transition to 'killed' """ try: - _kill(req, image_id) + _kill(req, image_id, from_state) except Exception: LOG.exception(_("Unable to kill image %(id)s: ") % {'id': image_id}) @@ -119,7 +125,7 @@ def upload_data_to_store(req, image_meta, image_data, store, notifier): 'supplied': supplied, 'actual': actual}) LOG.error(msg) - safe_kill(req, image_id) + safe_kill(req, image_id, 'saving') initiate_deletion(req, location, image_id, CONF.delayed_delete) raise webob.exc.HTTPBadRequest(explanation=msg, content_type="text/plain", @@ -142,7 +148,8 @@ def upload_data_to_store(req, image_meta, image_data, store, notifier): try: image_meta = registry.update_image_metadata(req.context, image_id, - update_data) + update_data, + from_state='saving') except exception.NotFound as e: msg = _("Image %s could not be found after upload. The image may " @@ -174,7 +181,7 @@ def upload_data_to_store(req, image_meta, image_data, store, notifier): except exception.Forbidden as e: msg = u"Forbidden upload attempt: %s" % e LOG.debug(msg) - safe_kill(req, image_id) + safe_kill(req, image_id, 'saving') notifier.error('image.upload', msg) raise webob.exc.HTTPForbidden(explanation=msg, request=req, @@ -183,7 +190,7 @@ def upload_data_to_store(req, image_meta, image_data, store, notifier): except exception.StorageFull as e: msg = _("Image storage media is full: %s") % e LOG.error(msg) - safe_kill(req, image_id) + safe_kill(req, image_id, 'saving') notifier.error('image.upload', msg) raise webob.exc.HTTPRequestEntityTooLarge(explanation=msg, request=req, @@ -192,7 +199,7 @@ def upload_data_to_store(req, image_meta, image_data, store, notifier): except exception.StorageWriteDenied as e: msg = _("Insufficient permissions on image storage media: %s") % e LOG.error(msg) - safe_kill(req, image_id) + safe_kill(req, image_id, 'saving') notifier.error('image.upload', msg) raise webob.exc.HTTPServiceUnavailable(explanation=msg, request=req, @@ -202,7 +209,7 @@ def upload_data_to_store(req, image_meta, image_data, store, notifier): msg = (_("Denying attempt to upload image larger than %d bytes.") % CONF.image_size_cap) LOG.info(msg) - safe_kill(req, image_id) + safe_kill(req, image_id, 'saving') notifier.error('image.upload', msg) raise webob.exc.HTTPRequestEntityTooLarge(explanation=msg, request=req, @@ -212,7 +219,7 @@ def upload_data_to_store(req, image_meta, image_data, store, notifier): msg = (_("Denying attempt to upload image because it exceeds the ." "quota: %s") % e) LOG.info(msg) - safe_kill(req, image_id) + safe_kill(req, image_id, 'saving') notifier.error('image.upload', msg) raise webob.exc.HTTPRequestEntityTooLarge(explanation=msg, request=req, @@ -227,12 +234,12 @@ def upload_data_to_store(req, image_meta, image_data, store, notifier): notifier.error('image.upload', msg) with excutils.save_and_reraise_exception(): LOG.exception(msg) - safe_kill(req, image_id) + safe_kill(req, image_id, 'saving') except (ValueError, IOError) as e: msg = _("Client disconnected before sending all data to backend") LOG.debug(msg) - safe_kill(req, image_id) + safe_kill(req, image_id, 'saving') raise webob.exc.HTTPBadRequest(explanation=msg, content_type="text/plain", request=req) @@ -240,7 +247,7 @@ def upload_data_to_store(req, image_meta, image_data, store, notifier): except Exception as e: msg = _("Failed to upload image %s") % image_id LOG.exception(msg) - safe_kill(req, image_id) + safe_kill(req, image_id, 'saving') notifier.error('image.upload', msg) raise webob.exc.HTTPInternalServerError(explanation=msg, request=req, diff --git a/glance/tests/unit/v1/test_api.py b/glance/tests/unit/v1/test_api.py index ab693c060b..5618cb085f 100644 --- a/glance/tests/unit/v1/test_api.py +++ b/glance/tests/unit/v1/test_api.py @@ -94,6 +94,8 @@ class TestGlanceAPI(base.IsolatedUnitTest): db_api.get_engine() self.destroy_fixtures() self.create_fixtures() + # Used to store/track image status changes for post-analysis + self.image_status = [] def tearDown(self): """Clear the test environment""" @@ -1195,7 +1197,7 @@ class TestGlanceAPI(base.IsolatedUnitTest): res = req.get_response(self.api) self.assertEqual(res.status_int, 200) - # Verify the status is deleted + # Verify the status is 'deleted' req = webob.Request.blank("/images/%s" % UUID2) req.method = 'HEAD' res = req.get_response(self.api) @@ -1209,7 +1211,7 @@ class TestGlanceAPI(base.IsolatedUnitTest): msg = "Image %s not found." % UUID2 self.assertTrue(msg in res.body) - # Verify the status is still deleted + # Verify the status is still 'deleted' req = webob.Request.blank("/images/%s" % UUID2) req.method = 'HEAD' res = req.get_response(self.api) @@ -1249,7 +1251,7 @@ class TestGlanceAPI(base.IsolatedUnitTest): res = req.get_response(self.api) self.assertEqual(res.status_int, 200) - # Verify the status is pending_delete + # Verify the status is 'pending_delete' req = webob.Request.blank("/images/%s" % UUID2) req.method = 'HEAD' res = req.get_response(self.api) @@ -1264,7 +1266,7 @@ class TestGlanceAPI(base.IsolatedUnitTest): self.assertTrue('Forbidden to delete a pending_delete image' in res.body) - # Verify the status is still pending_delete + # Verify the status is still 'pending_delete' req = webob.Request.blank("/images/%s" % UUID2) req.method = 'HEAD' res = req.get_response(self.api) @@ -1274,9 +1276,9 @@ class TestGlanceAPI(base.IsolatedUnitTest): def test_upload_to_image_status_saving(self): """Test image upload conflict. - If an image is uploaded before an existing upload operation completes - to the same image, the original image should succeed and the - conflicting should fail and any data deleted. + If an image is uploaded before an existing upload to the same image + completes, the original upload should succeed and the conflicting + one should fail and any data be deleted. """ fixture_headers = {'x-image-meta-store': 'file', 'x-image-meta-disk-format': 'vhd', @@ -1302,9 +1304,10 @@ class TestGlanceAPI(base.IsolatedUnitTest): orig_get_image_metadata = registry.get_image_metadata orig_image_get = db_api._image_get orig_image_update = db_api._image_update + orig_initiate_deletion = upload_utils.initiate_deletion # this will be used to track what is called and their order. - called = [] + call_sequence = [] # use this to determine if we are within a db session i.e. atomic # operation, that is setting our active state. test_status = {'activate_session_started': False} @@ -1312,15 +1315,24 @@ class TestGlanceAPI(base.IsolatedUnitTest): # guard. test_status['queued_guard_passed'] = False + state_changes = [] + def mock_image_update(context, values, image_id, purge_props=False, from_state=None): - if values.get('status', None) == 'active': - # We only expect this state to be entered once. - if test_status['activate_session_started']: - raise Exception("target session already started") - test_status['activate_session_started'] = True - called.append('update_active') + status = values.get('status') + if status: + state_changes.append(status) + if status == 'active': + # We only expect this state to be entered once. + if test_status['activate_session_started']: + raise Exception("target session already started") + + test_status['activate_session_started'] = True + call_sequence.append('update_active') + + else: + call_sequence.append('update') return orig_image_update(context, values, image_id, purge_props=purge_props, @@ -1335,7 +1347,7 @@ class TestGlanceAPI(base.IsolatedUnitTest): """ image = orig_image_get(*args, **kwargs) if test_status['activate_session_started']: - called.append('image_get_active') + call_sequence.append('image_get_active') setattr(image, 'status', 'active') else: setattr(image, 'status', 'saving') @@ -1345,7 +1357,7 @@ class TestGlanceAPI(base.IsolatedUnitTest): def mock_get_image_metadata(*args, **kwargs): """Force image status sequence. """ - called.append('get_image_meta') + call_sequence.append('get_image_meta') meta = orig_get_image_metadata(*args, **kwargs) if not test_status['queued_guard_passed']: meta['status'] = 'queued' @@ -1353,27 +1365,47 @@ class TestGlanceAPI(base.IsolatedUnitTest): return meta + def mock_initiate_deletion(*args, **kwargs): + call_sequence.append('init_del') + orig_initiate_deletion(*args, **kwargs) + req = webob.Request.blank("/images/%s" % image_id) req.method = 'PUT' req.headers['Content-Type'] = \ 'application/octet-stream' req.body = "chunk00000remainder" - mpo = mock.patch.object - with mpo(upload_utils, 'initiate_deletion') as mock_initiate_deletion: - with mpo(registry, 'get_image_metadata', mock_get_image_metadata): - with mpo(db_api, '_image_get', mock_image_get): - with mpo(db_api, '_image_update', mock_image_update): + with mock.patch.object(upload_utils, 'initiate_deletion') as \ + mock_init_del: + mock_init_del.side_effect = mock_initiate_deletion + with mock.patch.object(registry, 'get_image_metadata') as \ + mock_get_meta: + mock_get_meta.side_effect = mock_get_image_metadata + with mock.patch.object(db_api, '_image_get') as mock_db_get: + mock_db_get.side_effect = mock_image_get + with mock.patch.object(db_api, '_image_update') as \ + mock_db_update: + mock_db_update.side_effect = mock_image_update + + # Expect a 409 Conflict. res = req.get_response(self.api) self.assertEqual(res.status_int, 409) # Check expected call sequence self.assertEqual(['get_image_meta', 'get_image_meta', - 'update_active', 'image_get_active'], - called) + 'update', 'update_active', + 'image_get_active', + 'init_del'], + call_sequence) - # Ensure cleanup occurred. - self.assertTrue(mock_initiate_deletion.called) + self.assertTrue(mock_get_meta.called) + self.assertTrue(mock_db_get.called) + self.assertTrue(mock_db_update.called) + + # Ensure cleanup occured. + self.assertEqual(1, mock_init_del.call_count) + + self.assertEqual(state_changes, ['saving', 'active']) def test_register_and_upload(self): """ @@ -1422,7 +1454,7 @@ class TestGlanceAPI(base.IsolatedUnitTest): res = req.get_response(self.api) self.assertEqual(res.status_int, 200) - # Verify the status is queued + # Verify the status is 'queued' req = webob.Request.blank("/images/%s" % image_id) req.method = 'HEAD' @@ -1433,6 +1465,124 @@ class TestGlanceAPI(base.IsolatedUnitTest): "Got headers: %r" % res.headers) self.assertEqual("active", res.headers['x-image-meta-status']) + def _get_image_status(self, image_id): + req = webob.Request.blank("/images/%s" % image_id) + req.method = 'HEAD' + return req.get_response(self.api) + + def _verify_image_status(self, image_id, status, check_deleted=False, + use_cached=False): + if not use_cached: + res = self._get_image_status(image_id) + else: + res = self.image_status.pop(0) + + self.assertEqual(200, res.status_int) + self.assertEqual(res.headers['x-image-meta-status'], status) + self.assertEqual(res.headers['x-image-meta-deleted'], + str(check_deleted)) + + def _upload_safe_kill_common(self, mocks): + fixture_headers = {'x-image-meta-store': 'file', + 'x-image-meta-disk-format': 'vhd', + 'x-image-meta-container-format': 'ovf', + 'x-image-meta-name': 'fake image #3', + 'x-image-meta-property-key1': 'value1'} + + req = webob.Request.blank("/images") + req.method = 'POST' + for k, v in fixture_headers.iteritems(): + req.headers[k] = v + + res = req.get_response(self.api) + self.assertEqual(201, res.status_int) + res_body = jsonutils.loads(res.body)['image'] + + self.assertTrue('id' in res_body) + + self.image_id = res_body['id'] + self.assertTrue('/images/%s' % + self.image_id in res.headers['location']) + + # Verify the status is 'queued' + self.assertEqual('queued', res_body['status']) + + for m in mocks: + m['mock'].side_effect = m['side_effect'] + + # Now upload the image file along with some more metadata and + # verify original metadata properties are not marked deleted + req = webob.Request.blank("/images/%s" % self.image_id) + req.method = 'PUT' + req.headers['Content-Type'] = 'application/octet-stream' + req.headers['x-image-meta-property-key2'] = 'value2' + req.body = "chunk00000remainder" + res = req.get_response(self.api) + # We expect 500 since an exception occured during upload. + self.assertEqual(500, res.status_int) + + @mock.patch('glance.store.store_add_to_backend') + def test_upload_safe_kill(self, mock_store_add_to_backend): + + def mock_store_add_to_backend_w_exception(*args, **kwargs): + """Trigger mid-upload failure by raising an exception.""" + self.image_status.append(self._get_image_status(self.image_id)) + # Raise an exception to emulate failed upload. + raise Exception("== UNIT TEST UPLOAD EXCEPTION ==") + + mocks = [{'mock': mock_store_add_to_backend, + 'side_effect': mock_store_add_to_backend_w_exception}] + + self._upload_safe_kill_common(mocks) + + # Check we went from 'saving' -> 'killed' + self._verify_image_status(self.image_id, 'saving', use_cached=True) + self._verify_image_status(self.image_id, 'killed') + + self.assertEqual(1, mock_store_add_to_backend.call_count) + + @mock.patch('glance.store.store_add_to_backend') + def test_upload_safe_kill_deleted(self, mock_store_add_to_backend): + test_router_api = router.API(self.mapper) + self.api = test_utils.FakeAuthMiddleware(test_router_api, + is_admin=True) + + def mock_store_add_to_backend_w_exception(*args, **kwargs): + """We now delete the image, assert status is 'deleted' then + raise an exception to emulate a failed upload. This will be caught + by upload_data_to_store() which will then try to set status to + 'killed' which will be ignored since the image has been deleted. + """ + # expect 'saving' + self.image_status.append(self._get_image_status(self.image_id)) + + req = webob.Request.blank("/images/%s" % self.image_id) + req.method = 'DELETE' + res = req.get_response(self.api) + self.assertEqual(200, res.status_int) + + # expect 'deleted' + self.image_status.append(self._get_image_status(self.image_id)) + + # Raise an exception to make the upload fail. + raise Exception("== UNIT TEST UPLOAD EXCEPTION ==") + + mocks = [{'mock': mock_store_add_to_backend, + 'side_effect': mock_store_add_to_backend_w_exception}] + + self._upload_safe_kill_common(mocks) + + # Check we went from 'saving' -> 'deleted' -> 'deleted' + self._verify_image_status(self.image_id, 'saving', check_deleted=False, + use_cached=True) + + self._verify_image_status(self.image_id, 'deleted', check_deleted=True, + use_cached=True) + + self._verify_image_status(self.image_id, 'deleted', check_deleted=True) + + self.assertEqual(1, mock_store_add_to_backend.call_count) + def test_delete_during_image_upload(self): req = unit_test_utils.get_fake_request() @@ -1456,7 +1606,7 @@ class TestGlanceAPI(base.IsolatedUnitTest): image_id = res_body['id'] self.assertTrue('/images/%s' % image_id in res.headers['location']) - # Verify the status is queued + # Verify the status is 'queued' self.assertEqual('queued', res_body['status']) called = {'initiate_deletion': False} diff --git a/glance/tests/unit/v1/test_upload_utils.py b/glance/tests/unit/v1/test_upload_utils.py index ea54f1dfeb..18a3b66759 100644 --- a/glance/tests/unit/v1/test_upload_utils.py +++ b/glance/tests/unit/v1/test_upload_utils.py @@ -69,10 +69,11 @@ class TestUploadUtils(base.StoreClearingUnitTest): id = unit_test_utils.UUID1 self.mox.StubOutWithMock(registry, "update_image_metadata") - registry.update_image_metadata(req.context, id, {'status': 'killed'}) + registry.update_image_metadata(req.context, id, {'status': 'killed'}, + 'saving') self.mox.ReplayAll() - upload_utils.safe_kill(req, id) + upload_utils.safe_kill(req, id, 'saving') self.mox.VerifyAll() @@ -83,11 +84,12 @@ class TestUploadUtils(base.StoreClearingUnitTest): self.mox.StubOutWithMock(registry, "update_image_metadata") registry.update_image_metadata(req.context, id, - {'status': 'killed'} + {'status': 'killed'}, + 'saving' ).AndRaise(Exception()) self.mox.ReplayAll() - upload_utils.safe_kill(req, id) + upload_utils.safe_kill(req, id, 'saving') self.mox.VerifyAll() @@ -109,12 +111,13 @@ class TestUploadUtils(base.StoreClearingUnitTest): mox.IgnoreArg(), image_meta['size']).AndReturn((location, size, checksum, {})) - self.mox.StubOutWithMock(registry, "update_image_metadata") + self.mox.StubOutWithMock(registry, 'update_image_metadata') update_data = {'checksum': checksum, 'size': size} - registry.update_image_metadata( - req.context, image_meta['id'], - update_data).AndReturn(image_meta.update(update_data)) + registry.update_image_metadata(req.context, image_meta['id'], + update_data, from_state='saving' + ).AndReturn( + image_meta.update(update_data)) self.mox.ReplayAll() actual_meta, actual_loc, loc_meta = upload_utils.upload_data_to_store( @@ -210,7 +213,7 @@ class TestUploadUtils(base.StoreClearingUnitTest): image_meta['size']).AndRaise(exc_class) self.mox.StubOutWithMock(upload_utils, "safe_kill") - upload_utils.safe_kill(req, image_meta['id']) + upload_utils.safe_kill(req, image_meta['id'], 'saving') self.mox.ReplayAll() self.assertRaises(expected_class, @@ -239,7 +242,7 @@ class TestUploadUtils(base.StoreClearingUnitTest): if image_killed: self.mox.StubOutWithMock(upload_utils, "safe_kill") - upload_utils.safe_kill(req, image_meta['id']) + upload_utils.safe_kill(req, image_meta['id'], 'saving') notifier = self.mox.CreateMockAnything() notifier.error('image.upload', mox.IgnoreArg()) @@ -318,18 +321,17 @@ class TestUploadUtils(base.StoreClearingUnitTest): mox.IgnoreArg(), image_meta['size']).AndReturn((location, size, checksum, {})) - self.mox.StubOutWithMock(registry, "update_image_metadata") + self.mox.StubOutWithMock(registry, 'update_image_metadata') update_data = {'checksum': checksum, 'size': size} - registry.update_image_metadata(req.context, - image_meta['id'], - update_data + registry.update_image_metadata(req.context, image_meta['id'], + update_data, from_state='saving' ).AndRaise(exception.NotFound) self.mox.StubOutWithMock(upload_utils, "initiate_deletion") upload_utils.initiate_deletion(req, location, image_meta['id'], mox.IsA(bool)) self.mox.StubOutWithMock(upload_utils, "safe_kill") - upload_utils.safe_kill(req, image_meta['id']) + upload_utils.safe_kill(req, image_meta['id'], 'saving') notifier.error('image.upload', mox.IgnoreArg()) self.mox.ReplayAll()