Merge pull request #338 from willu47/issue-337

Remove top level verbosity cli argument.

- `smif -vv list` or `smif -vv run <modelrun>` are no longer valid commands
- `smif run <modelrun> -vv` verbosity flags are added to the sub-commands not the parent command

Author: Will Usher

README.rst

@@ -222,7 +222,7 @@ and simulation model.
 To see all options and flags::
 
         $ smif --help
-        usage: smif [-h] [-V] [-v] {setup,list,run} ...
+        usage: smif [-h] [-V] {setup,list,run} ...
 
         Command line tools for smif
 
@@ -236,8 +236,6 @@ To see all options and flags::
         optional arguments:
         -h, --help        show this help message and exit
         -V, --version     show the current version of smif
-        -v, --verbose     show messages: -v to see messages reporting on progress,
-                            -vv to see debug messages.
 
 Citation
 ========

docs/getting_started.rst

@@ -18,7 +18,7 @@ Setup
 First, check smif has installed correctly by typing on the command line::
 
     $ smif
-    usage: smif [-h] [-V] [-v] {setup,list,app,run} ...
+    usage: smif [-h] [-V] {setup,list,app,run} ...
 
     Command line tools for smif
 
@@ -32,8 +32,6 @@ First, check smif has installed correctly by typing on the command line::
     optional arguments:
     -h, --help            show this help message and exit
     -V, --version         show the current version of smif
-    -v, --verbose         show messages: -v to see messages reporting on
-                            progress, -vv to see debug messages.
 
 
 You can also check which version is installed::

src/smif/cli/__init__.py

@@ -65,43 +65,40 @@
 """
 from __future__ import print_function
 
+import logging
+import os
+import sys
+from argparse import ArgumentParser
+
+import pkg_resources
+
+import smif
+import smif.cli.log
+from smif.controller import (ModelRunScheduler, copy_project_folder,
+                             execute_model_run)
+from smif.data_layer import Store
+from smif.data_layer.file import (CSVDataStore, FileMetadataStore,
+                                  ParquetDataStore, YamlConfigStore)
+from smif.http_api import create_app
+
 try:
     import _thread
 except ImportError:
     import thread as _thread
 
-import logging
-import logging.config
-import os
-import pkg_resources
 
 try:
     import win32api
     USE_WIN32 = True
 except ImportError:
     USE_WIN32 = False
 
-from argparse import ArgumentParser
-import sys
-
-import smif
-import smif.cli.log
-
-from smif.controller import copy_project_folder, execute_model_run, ModelRunScheduler
-from smif.http_api import create_app
-from smif.data_layer import Store
-from smif.data_layer.file import (CSVDataStore, FileMetadataStore, ParquetDataStore,
-                                  YamlConfigStore)
-
 
 __author__ = "Will Usher, Tom Russell"
 __copyright__ = "Will Usher, Tom Russell"
 __license__ = "mit"
 
 
-LOGGER = logging.getLogger(__name__)
-
-
 def list_model_runs(args):
     """List the model runs defined in the config
     """
@@ -119,7 +116,8 @@ def run_model_runs(args):
     ----------
     args
     """
-    LOGGER.profiling_start('run_model_runs', '{:s}, {:s}, {:s}'.format(
+    logger = logging.getLogger(__name__)
+    logger.profiling_start('run_model_runs', '{:s}, {:s}, {:s}'.format(
         args.modelrun, args.interface, args.directory))
     if args.batchfile:
         with open(args.modelrun, 'r') as f:
@@ -129,9 +127,9 @@ def run_model_runs(args):
 
     store = _get_store(args)
     execute_model_run(model_run_ids, store, args.warm)
-    LOGGER.profiling_stop('run_model_runs', '{:s}, {:s}, {:s}'.format(
+    logger.profiling_stop('run_model_runs', '{:s}, {:s}, {:s}'.format(
         args.modelrun, args.interface, args.directory))
-    LOGGER.summary()
+    logger.summary()
 
 
 def _get_store(args):
@@ -221,10 +219,6 @@ def parse_arguments():
                         action='version',
                         version="smif " + smif.__version__,
                         help='show the current version of smif')
-    parser.add_argument('-v', '--verbose',
-                        action='count',
-                        help='show messages: -v to see messages reporting on progress, ' +
-                        '-vv to see debug messages.')
 
     parent_parser = ArgumentParser(add_help=False)
     parent_parser.add_argument('-v', '--verbose',
@@ -334,6 +328,7 @@ def main(arguments=None):
     """
     parser = parse_arguments()
     args = parser.parse_args(arguments)
+    smif.cli.log.setup_logging(args.verbose)
 
     def exception_handler(exception_type, exception, traceback, debug_hook=sys.excepthook):
         if args.verbose:

src/smif/cli/log.py

@@ -5,37 +5,6 @@
 import sys
 from collections import OrderedDict
 
-LOGGING_CONFIG = {
-    'version': 1,
-    'formatters': {
-        'default': {
-            'format': '%(asctime)s %(name)-12s: %(levelname)-8s %(message)s'
-        },
-        'message': {
-            'format': '\033[1;34m%(levelname)-8s\033[0m %(message)s'
-        }
-    },
-    'handlers': {
-        'file': {
-            'class': 'logging.FileHandler',
-            'level': 'DEBUG',
-            'formatter': 'default',
-            'filename': 'smif.log',
-            'mode': 'a',
-            'encoding': 'utf-8'
-        },
-        'stream': {
-            'class': 'logging.StreamHandler',
-            'formatter': 'message',
-            'level': 'DEBUG'
-        }
-    },
-    'root': {
-        'handlers': ['file', 'stream'],
-        'level': 'DEBUG'
-    }
-}
-
 
 # Make profiling methods available through the logger
 def profiling_start(self, operation, key):
@@ -100,28 +69,50 @@ def summary(self, *args, **kws):
             self._log(logging.INFO, entry, args)
 
 
+def setup_logging(loglevel):
+    config = {
+        'version': 1,
+        'formatters': {
+            'default': {
+                'format': '%(asctime)s %(name)-12s: %(levelname)-8s %(message)s'
+            },
+            'message': {
+                'format': '\033[1;34m%(levelname)-8s\033[0m %(message)s'
+            }
+        },
+        'handlers': {
+            'file': {
+                'class': 'logging.FileHandler',
+                'level': 'DEBUG',
+                'formatter': 'default',
+                'filename': 'smif.log',
+                'mode': 'a',
+                'encoding': 'utf-8'
+            },
+            'stream': {
+                'class': 'logging.StreamHandler',
+                'formatter': 'message',
+                'level': 'DEBUG'
+            }
+        },
+        'root': {
+            'handlers': ['file', 'stream'],
+            'level': 'DEBUG'
+        }
+    }
+
+    if loglevel is None:
+        config['root']['level'] = logging.WARNING
+    elif loglevel == 1:
+        config['root']['level'] = logging.INFO
+    else:
+        config['root']['level'] = logging.DEBUG
+
+    logging.config.dictConfig(config)
+    logging.debug('Debug logging enabled.')
+
+
 logging.Logger.profiling_start = profiling_start
 logging.Logger.profiling_stop = profiling_stop
 logging.Logger.summary = summary
 logging.Logger._profile = OrderedDict()
-
-# Configure logging once, outside of any dependency on argparse
-VERBOSITY = None
-if '--verbose' in sys.argv:
-    VERBOSITY = sys.argv.count('--verbose')
-else:
-    for arg in sys.argv:
-        if re.match(r'\A-v+\Z', arg):
-            VERBOSITY = len(arg) - 1
-            break
-
-if VERBOSITY is None:
-    LOGGING_CONFIG['root']['level'] = logging.WARNING
-elif VERBOSITY == 1:
-    LOGGING_CONFIG['root']['level'] = logging.INFO
-else:
-    LOGGING_CONFIG['root']['level'] = logging.DEBUG
-
-logging.config.dictConfig(LOGGING_CONFIG)
-LOGGER = logging.getLogger(__name__)
-LOGGER.debug('Debug logging enabled.')

src/smif/controller/build.py

@@ -8,8 +8,6 @@
 from smif.exception import SmifDataNotFoundError
 from smif.model import ScenarioModel, SosModel
 
-LOGGER = logging.getLogger(__name__)
-
 
 def get_model_run_definition(store, modelrun):
     """Builds the model run
@@ -31,26 +29,26 @@ def get_model_run_definition(store, modelrun):
     try:
         model_run_config = store.read_model_run(modelrun)
     except SmifDataNotFoundError:
-        LOGGER.error("Model run %s not found. Run 'smif list' to see available model runs.",
+        logging.error("Model run %s not found. Run 'smif list' to see available model runs.",
                      modelrun)
         exit(-1)
 
-    LOGGER.info("Running %s", model_run_config['name'])
-    LOGGER.debug("Model Run: %s", model_run_config)
+    logging.info("Running %s", model_run_config['name'])
+    logging.debug("Model Run: %s", model_run_config)
     sos_model_config = store.read_sos_model(model_run_config['sos_model'])
 
     sector_models = get_sector_models(sos_model_config['sector_models'], store)
-    LOGGER.debug("Sector models: %s", sector_models)
+    logging.debug("Sector models: %s", sector_models)
 
     scenario_models = get_scenario_models(model_run_config['scenarios'], store)
-    LOGGER.debug("Scenario models: %s", [model.name for model in scenario_models])
+    logging.debug("Scenario models: %s", [model.name for model in scenario_models])
 
     sos_model = SosModel.from_dict(sos_model_config, sector_models + scenario_models)
     model_run_config['sos_model'] = sos_model
-    LOGGER.debug("Model list: %s", list(model.name for model in sos_model.models))
+    logging.debug("Model list: %s", list(model.name for model in sos_model.models))
 
     model_run_config['strategies'] = store.read_strategies(model_run_config['name'])
-    LOGGER.debug("Strategies: %s", [s['type'] for s in model_run_config['strategies']])
+    logging.debug("Strategies: %s", [s['type'] for s in model_run_config['strategies']])
 
     return model_run_config
 
@@ -78,7 +76,7 @@ def get_scenario_models(scenarios, handler):
         scenario_definition['outputs'] = scenario_definition['provides']
         del scenario_definition['provides']
 
-        LOGGER.debug("Scenario definition: %s", scenario_name)
+        logging.debug("Scenario definition: %s", scenario_name)
 
         scenario_model = ScenarioModel.from_dict(scenario_definition)
         scenario_models.append(scenario_model)
@@ -123,7 +121,8 @@ def build_model_run(model_run_config):
     -------
     `smif.controller.modelrun.ModelRun`
     """
-    LOGGER.profiling_start('build_model_run', model_run_config['name'])
+    logger = logging.getLogger()
+    logger.profiling_start('build_model_run', model_run_config['name'])
     try:
         builder = ModelRunBuilder()
         builder.construct(model_run_config)
@@ -133,10 +132,10 @@ def build_model_run(model_run_config):
         traceback.print_exception(err_type, err_value, err_traceback)
         err_msg = str(error)
         if err_msg:
-            LOGGER.error("An AssertionError occurred (%s) see details above.", err_msg)
+            logger.error("An AssertionError occurred (%s) see details above.", err_msg)
         else:
-            LOGGER.error("An AssertionError occurred, see details above.")
+            logger.error("An AssertionError occurred, see details above.")
         exit(-1)
 
-    LOGGER.profiling_stop('build_model_run', model_run_config['name'])
+    logger.profiling_stop('build_model_run', model_run_config['name'])
     return modelrun

src/smif/controller/execute.py

@@ -4,8 +4,6 @@
 from smif.controller.build import build_model_run, get_model_run_definition
 from smif.exception import SmifModelRunError
 
-LOGGER = logging.getLogger(__name__)
-
 
 def execute_model_run(model_run_ids, store, warm=False):
     """Runs the model run
@@ -17,23 +15,23 @@ def execute_model_run(model_run_ids, store, warm=False):
     """
     model_run_definitions = []
     for model_run in model_run_ids:
-        LOGGER.info("Getting model run definition for '%s'", model_run)
+        logging.info("Getting model run definition for '%s'", model_run)
         model_run_definitions.append(get_model_run_definition(store, model_run))
 
     for model_run_config in model_run_definitions:
 
-        LOGGER.info("Build model run from configuration data")
+        logging.info("Build model run from configuration data")
         modelrun = build_model_run(model_run_config)
 
-        LOGGER.info("Running model run %s", modelrun.name)
+        logging.info("Running model run %s", modelrun.name)
 
         try:
             if warm:
                 modelrun.run(store, store.prepare_warm_start(modelrun.name))
             else:
                 modelrun.run(store)
         except SmifModelRunError as ex:
-            LOGGER.exception(ex)
+            logging.exception(ex)
             exit(1)
 
         print("Model run '%s' complete" % modelrun.name)

src/smif/controller/setup.py

@@ -4,8 +4,6 @@
 
 import pkg_resources
 
-LOGGER = logging.getLogger(__name__)
-
 
 def copy_project_folder(directory):
     """Creates folder structure in the target directory
@@ -20,7 +18,7 @@ def copy_project_folder(directory):
         dirname = "the current directory"
     else:
         dirname = directory
-    LOGGER.info("Created sample project in %s", dirname)
+    logging.info("Created sample project in %s", dirname)
 
 
 def _recursive_overwrite(pkg, src, dest):