Fix logging for cli commands. Add logging to db upgrade etc.

ckan/lib/cli.py

@@ -3,11 +3,15 @@
 import sys
 import logging
 from pprint import pprint
+import re
 
 import paste.script
 from paste.registry import Registry
 from paste.script.util.logging_config import fileConfig
-import re
+
+#NB No CKAN imports are allowed until after the config file is loaded.
+#   i.e. do the imports in methods, after _load_config is called.
+#   Otherwise loggers get disabled.
 
 class MockTranslator(object):
     def gettext(self, value):
@@ -33,11 +37,7 @@ class CkanCommand(paste.script.command.Command):
     group_name = 'ckan'
 
     def _load_config(self):
-        # Avoids vdm logging warning
-        logging.basicConfig(level=logging.ERROR)
-
         from paste.deploy import appconfig
-        from ckan.config.environment import load_environment
         if not self.options.config:
             msg = 'No config file supplied'
             raise self.BadCommand(msg)
@@ -46,6 +46,10 @@ def _load_config(self):
             raise AssertionError('Config filename %r does not exist.' % self.filename)
         fileConfig(self.filename)
         conf = appconfig('config:' + self.filename)
+        assert 'ckan' not in dir() # otherwise loggers would be disabled
+        # We have now loaded the config. Now we can import ckan for the
+        # first time.
+        from ckan.config.environment import load_environment
         load_environment(conf.global_conf, conf.local_conf)
 
         self.registry=Registry()

ckan/model/__init__.py

@@ -96,6 +96,7 @@ def init_db(self):
 
                 self.init_configuration_data()
                 self.tables_created_and_initialised = True
+        log.info('Database initialised')
 
     def clean_db(self):
         metadata = MetaData(self.metadata.bind)
@@ -105,6 +106,7 @@ def clean_db(self):
 
         metadata.drop_all()
         self.tables_created_and_initialised = False
+        log.info('Database tables dropped')
 
     def init_const_data(self):
         '''Creates 'constant' objects that should always be there in
@@ -137,6 +139,7 @@ def create_db(self):
         self.metadata.create_all(bind=self.metadata.bind)
         self.init_const_data()
         self.init_configuration_data()
+        log.info('Database tables created')
 
     def latest_migration_version(self):
         import migrate.versioning.api as mig
@@ -158,6 +161,7 @@ def rebuild_db(self):
         self.session.remove()
         self.init_db()
         self.session.flush()
+        log.info('Database rebuilt')
 
     def delete_all(self):
         '''Delete all data from all tables.'''
@@ -171,7 +175,7 @@ def delete_all(self):
         for table in tables:
             connection.execute('delete from "%s"' % table.name)
         self.session.commit()
-
+        log.info('Database table data deleted')
 
     def setup_migration_version_control(self, version=None):
         import migrate.exceptions
@@ -193,9 +197,16 @@ def upgrade_db(self, version=None):
             meta.engine.name
         import migrate.versioning.api as mig
         self.setup_migration_version_control()
+        version_before = mig.db_version(self.metadata.bind, self.migrate_repository)
         mig.upgrade(self.metadata.bind, self.migrate_repository, version=version)
-        self.init_const_data()
+        version_after = mig.db_version(self.metadata.bind, self.migrate_repository)
+        if version_after != version_before:
+            log.info('CKAN database version upgraded: %s -> %s', version_before, version_after)
+        else:
+            log.info('CKAN database version remains as: %s', version_after)
 
+        self.init_const_data()
+
         ##this prints the diffs in a readable format
         ##import pprint
         ##from migrate.versioning.schemadiff import getDiffOfModelAgainstDatabase