Provide user friendly message for FK failure

'glance-manage db purge' command fails with DBReferenceError due
to FK constraint failure and exits with stack-trace on the command
prompt.

Made changes to give user-friendly error message to the user as
well as log appropriate error message in glance-manage logs
instead of stack-trace.

Co-author-by: Dinesh Bhor <dinesh.bhor@nttdata.com>
Change-Id: I52e56b69f1b78408018c837d71d75c6df3df9e71
Closes-Bug: #1554412

glance/cmd/manage.py

@@ -42,6 +42,7 @@ if os.path.exists(os.path.join(possible_topdir, 'glance', '__init__.py')):
 from alembic import command as alembic_command
 
 from oslo_config import cfg
+from oslo_db import exception as db_exc
 from oslo_log import log as logging
 from oslo_utils import encodeutils
 import six
@@ -261,10 +262,14 @@ class DbCommands(object):
         if max_rows < 1:
             sys.exit(_("Minimal rows limit is 1."))
         ctx = context.get_admin_context(show_deleted=True)
+
         try:
             db_api.purge_deleted_rows(ctx, age_in_days, max_rows)
         except exception.Invalid as exc:
             sys.exit(exc.msg)
+        except db_exc.DBReferenceError:
+            sys.exit(_("Purge command failed, check glance-manage"
+                       " logs for more details."))
 
 
 class DbLegacyCommands(object):

glance/db/sqlalchemy/api.py

@@ -28,6 +28,7 @@ from oslo_config import cfg
 from oslo_db import exception as db_exception
 from oslo_db.sqlalchemy import session
 from oslo_log import log as logging
+from oslo_utils import excutils
 import osprofiler.sqlalchemy
 from retrying import retry
 import six
@@ -53,7 +54,7 @@ from glance.db.sqlalchemy.metadef_api import property as metadef_property_api
 from glance.db.sqlalchemy.metadef_api import tag as metadef_tag_api
 from glance.db.sqlalchemy import models
 from glance.db import utils as db_utils
-from glance.i18n import _, _LW, _LI
+from glance.i18n import _, _LW, _LI, _LE
 
 sa_logger = None
 LOG = logging.getLogger(__name__)
@@ -1297,7 +1298,7 @@ def purge_deleted_rows(context, age_in_days, max_rows, session=None):
             continue
         if hasattr(model_class, 'deleted'):
             tables.append(model_class.__tablename__)
-    # get rid of FX constraints
+    # get rid of FK constraints
     for tbl in ('images', 'tasks'):
         try:
             tables.remove(tbl)
@@ -1323,8 +1324,14 @@ def purge_deleted_rows(context, age_in_days, max_rows, session=None):
 
         delete_statement = DeleteFromSelect(tab, query_delete, column)
 
-        with session.begin():
-            result = session.execute(delete_statement)
+        try:
+            with session.begin():
+                result = session.execute(delete_statement)
+        except db_exception.DBReferenceError as ex:
+            with excutils.save_and_reraise_exception():
+                LOG.error(_LE('DBError detected when purging from '
+                          "%(tablename)s: %(error)s"),
+                          {'tablename': tbl, 'error': six.text_type(ex)})
 
         rows = result.rowcount
         LOG.info(_LI('Deleted %(rows)d row(s) from table %(tbl)s'),

glance/tests/functional/db/base.py

@@ -20,13 +20,17 @@ import datetime
 import uuid
 
 import mock
+from oslo_db import exception as db_exception
+from oslo_db.sqlalchemy import utils as sqlalchemyutils
 # NOTE(jokke): simplified transition to py3, behaves like py2 xrange
 from six.moves import range
 from six.moves import reduce
+from sqlalchemy.dialects import sqlite
 
 from glance.common import exception
 from glance.common import timeutils
 from glance import context
+from glance.db.sqlalchemy import api as db_api
 from glance.tests import functional
 import glance.tests.functional.db as db_tests
 from glance.tests import utils as test_utils
@@ -1979,6 +1983,75 @@ class DBPurgeTests(test_utils.BaseTestCase):
         tasks = self.db_api.task_get_all(self.adm_context)
         self.assertEqual(len(tasks), 2)
 
+    def test_purge_fk_constraint_failure(self):
+        """Test foreign key constraint failure
+
+        Test whether foreign key constraint failure during purge
+        operation is raising DBReferenceError or not.
+        """
+        session = db_api.get_session()
+        engine = db_api.get_engine()
+        connection = engine.connect()
+
+        dialect = engine.url.get_dialect()
+        if dialect == sqlite.dialect:
+            # We're seeing issues with foreign key support in SQLite 3.6.20
+            # SQLAlchemy doesn't support it at all with SQLite < 3.6.19
+            # It works fine in SQLite 3.7.
+            # So return early to skip this test if running SQLite < 3.7
+            if test_utils.is_sqlite_version_prior_to(3, 7):
+                self.skipTest(
+                    'sqlite version too old for reliable SQLA foreign_keys')
+            # This is required for enforcing Foreign Key Constraint
+            # in SQLite 3.x
+            connection.execute("PRAGMA foreign_keys = ON")
+
+        images = sqlalchemyutils.get_table(
+            engine, "images")
+        image_tags = sqlalchemyutils.get_table(
+            engine, "image_tags")
+
+        # Add a 4th row in images table and set it deleted 15 days ago
+        uuidstr = uuid.uuid4().hex
+        created_time = timeutils.utcnow() - datetime.timedelta(days=20)
+        deleted_time = created_time + datetime.timedelta(days=5)
+        images_row_fixture = {
+            'id': uuidstr,
+            'status': 'status',
+            'created_at': created_time,
+            'deleted_at': deleted_time,
+            'deleted': 1,
+            'visibility': 'public',
+            'min_disk': 1,
+            'min_ram': 1,
+            'protected': 0
+        }
+        ins_stmt = images.insert().values(**images_row_fixture)
+        connection.execute(ins_stmt)
+
+        # Add a record in image_tags referencing the above images record
+        # but do not set it as deleted
+        image_tags_row_fixture = {
+            'image_id': uuidstr,
+            'value': 'tag_value',
+            'created_at': created_time,
+            'deleted': 0
+        }
+        ins_stmt = image_tags.insert().values(**image_tags_row_fixture)
+        connection.execute(ins_stmt)
+
+        # Purge all records deleted at least 10 days ago
+        self.assertRaises(db_exception.DBReferenceError,
+                          db_api.purge_deleted_rows,
+                          self.adm_context,
+                          age_in_days=10,
+                          max_rows=50)
+
+        # Verify that no records from images have been deleted
+        # due to DBReferenceError being raised
+        images_rows = session.query(images).count()
+        self.assertEqual(4, images_rows)
+
 
 class TestVisibility(test_utils.BaseTestCase):
     def setUp(self):

glance/tests/unit/test_glance_manage.py

@@ -15,6 +15,7 @@
 #    under the License.
 
 import mock
+from oslo_db import exception as db_exception
 
 from glance.cmd import manage
 from glance import context
@@ -76,3 +77,11 @@ class DBCommandsTestCase(test_utils.BaseTestCase):
                                max_rows=value)
         expected = "'max_rows' value out of range, must not exceed 2147483647."
         self.assertEqual(expected, ex.code)
+
+    @mock.patch('glance.db.sqlalchemy.api.purge_deleted_rows')
+    def test_purge_command_fk_constraint_failure(self, purge_deleted_rows):
+        purge_deleted_rows.side_effect = db_exception.DBReferenceError(
+            'fake_table', 'fake_constraint', 'fake_key', 'fake_key_table')
+        exit = self.assertRaises(SystemExit, self.commands.purge, 10, 100)
+        self.assertEqual("Purge command failed, check glance-manage logs"
+                         " for more details.", exit.code)

glance/tests/utils.py

@@ -684,3 +684,9 @@ def db_sync(version=None, engine=None):
 
     alembic_config = alembic_migrations.get_alembic_config(engine=engine)
     alembic_command.upgrade(alembic_config, version)
+
+
+def is_sqlite_version_prior_to(major, minor):
+    import sqlite3
+    tup = sqlite3.sqlite_version_info
+    return tup[0] < major or (tup[0] == major and tup[1] < minor)