Merge "Fix image killed after deletion" into stable/icehouse

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)

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,

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
+        If an image is uploaded before an existing upload to the same image
-        to the same image, the original image should succeed and the
+        completes, the original upload should succeed and the conflicting
-        conflicting should fail and any data deleted.
+        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
+            status = values.get('status')
-                called.append('update_active')
+            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 mock.patch.object(upload_utils, 'initiate_deletion') as \
-        with mpo(upload_utils, 'initiate_deletion') as mock_initiate_deletion:
+                mock_init_del:
-            with mpo(registry, 'get_image_metadata', mock_get_image_metadata):
+            mock_init_del.side_effect = mock_initiate_deletion
-                with mpo(db_api, '_image_get', mock_image_get):
+            with mock.patch.object(registry, 'get_image_metadata') as \
-                    with mpo(db_api, '_image_update', mock_image_update):
+                    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'],
+                                          'update', 'update_active',
-                                         called)
+                                          'image_get_active',
+                                          'init_del'],
+                                         call_sequence)
 
-                        # Ensure cleanup occurred.
+                        self.assertTrue(mock_get_meta.called)
-                        self.assertTrue(mock_initiate_deletion.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}

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(
+        registry.update_image_metadata(req.context, image_meta['id'],
-            req.context, image_meta['id'],
+                                       update_data, from_state='saving'
-            update_data).AndReturn(image_meta.update(update_data))
+                                       ).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,
+        registry.update_image_metadata(req.context, image_meta['id'],
-                                       image_meta['id'],
+                                       update_data, from_state='saving'
-                                       update_data
                                        ).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()