Fixes LP Bug#844618 - SQLAlchemy errors not logged

Logs any import errors or SQLAlchemy connection failures
to the glance registry log so that there is some indication
that a driver module is not installed or there is a problem
with the sql_connection configuration string.

Adds test case that verifies log output and error raised.

(cherry picked from commit 56e15f6)

Change-Id: Ib86c353350530d6de62e577df57602d1762879f9

glance/registry/db/api.py

@@ -39,7 +39,8 @@
 _ENGINE = None
 _MAKER = None
 BASE = models.BASE
-logger = None
+sa_logger = None
+logger = logging.getLogger(__name__)
 
 # attributes common to all models
 BASE_MODEL_ATTRS = set(['id', 'created_at', 'updated_at', 'deleted_at',
@@ -64,22 +65,29 @@ def configure_db(options):
 
     :param options: Mapping of configuration options
     """
-    global _ENGINE
-    global logger
+    global _ENGINE, sa_logger, logger
     if not _ENGINE:
         debug = config.get_option(
             options, 'debug', type='bool', default=False)
         verbose = config.get_option(
             options, 'verbose', type='bool', default=False)
         timeout = config.get_option(
             options, 'sql_idle_timeout', type='int', default=3600)
-        _ENGINE = create_engine(options['sql_connection'],
-                                pool_recycle=timeout)
-        logger = logging.getLogger('sqlalchemy.engine')
+        sql_connection = config.get_option(options, 'sql_connection')
+        try:
+            _ENGINE = create_engine(sql_connection, pool_recycle=timeout)
+        except Exception, err:
+            msg = _("Error configuring registry database with supplied "
+                    "sql_connection '%(sql_connection)s'. "
+                    "Got error:\n%(err)s") % locals()
+            logger.error(msg)
+            raise
+
+        sa_logger = logging.getLogger('sqlalchemy.engine')
         if debug:
-            logger.setLevel(logging.DEBUG)
+            sa_logger.setLevel(logging.DEBUG)
         elif verbose:
-            logger.setLevel(logging.INFO)
+            sa_logger.setLevel(logging.INFO)
 
         models.register_models(_ENGINE)
 

glance/tests/unit/test_api.py

@@ -18,6 +18,7 @@
 import datetime
 import hashlib
 import httplib
+import logging
 import os
 import json
 import unittest
@@ -43,6 +44,50 @@
            'context_class': 'glance.registry.context.RequestContext'}
 
 
+class TestRegistryDb(unittest.TestCase):
+
+    def setUp(self):
+        """Establish a clean test environment"""
+        self.stubs = stubout.StubOutForTesting()
+
+    def test_bad_sql_connection(self):
+        """
+        Test that a bad sql_connection option supplied to the registry
+        API controller results in a) an Exception being thrown and b)
+        a message being logged to the registry log file...
+        """
+        bad_options = {'verbose': True,
+                       'debug': True,
+                       'sql_connection': 'baddriver:///'}
+        # We set this to None to trigger a reconfigure, otherwise
+        # other modules may have already correctly configured the DB
+        orig_engine = db_api._ENGINE
+        db_api._ENGINE = None
+        self.assertRaises(ImportError, db_api.configure_db,
+                          bad_options)
+        exc_raised = False
+        self.log_written = False
+
+        def fake_log_error(msg):
+            if 'Error configuring registry database' in msg:
+                self.log_written = True
+
+        self.stubs.Set(db_api.logger, 'error', fake_log_error)
+        try:
+            api_obj = rserver.API(bad_options)
+        except ImportError:
+            exc_raised = True
+        finally:
+            db_api._ENGINE = orig_engine
+
+        self.assertTrue(exc_raised)
+        self.assertTrue(self.log_written)
+
+    def tearDown(self):
+        """Clear the test environment"""
+        self.stubs.UnsetAll()
+
+
 class TestRegistryAPI(unittest.TestCase):
     def setUp(self):
         """Establish a clean test environment"""