Merge pull request #404 from tomalrussell/feature/run_once

Run a single model for a single timestep, with CLI subcommands.

Run 'smif run <modelrun> --dry-run' to see how to use these subcommands to
step through running a model run.

Essentially there are three steps:
- 'smif decide' sets up decisions and reports on the timesteps and decisions
  that the DecisionManager says should run
- 'smif before_step' initialises a model - this should only need to be run once
  per modelrun, and not all models do work in this step
- 'smif step' runs a single model for a single timestep and single decision,
  setting up the data handle and calling Model.simulate

Other changes of note:
- Skip testing database connection, which is otherwise unused - may be worth stripping out if there are no active plans to develop database backend.
- Handle one-dimensional DataArray to Dataframe conversions, with round-trip testing and in particular single-level MultiIndex handling. Surprising bug when dimension elements were not in alphabetical order led to misordered data.
- Allow concrete instances of Model, SectorModel to avoid needing to instantiate wrapper classes (with all dependencies) in the main smif process.
-  Refactor CLI tests to call smif.cli.main for ~4x speed-up (from about 2m to 30s), using pytest capsys fixture to capture stdout and stderr.

.appveyor.yml

@@ -37,6 +37,7 @@ install:
         shapely \
         xarray"
   - activate testenv
+  - pip install psycopg2-binary
   - python setup.py develop
 before_test:
   - PATH=C:\Program Files\PostgreSQL\9.6\bin\;%PATH%

ci/install.sh

@@ -47,13 +47,20 @@ if [[ "$DISTRIB" == "conda" ]]; then
         xarray \
         pandas \
         psycopg2 \
+        pyarrow \
         shapely \
         fiona
 
     source activate testenv
 fi
 
 pip install 'flake8>=3.7'
+
+if [[ "$PYTHON_VERSION" == "3.5" ]]; then
+    pip install 'Pint==0.9'
+    pip install 'jinja2>=2,<3'
+fi
+
 python setup.py develop
 
 # Install node and npm dependencies

docs/getting_started.rst

@@ -18,16 +18,30 @@ Setup
 First, check smif has installed correctly by typing on the command line::
 
     $ smif
-    usage: smif [-h] [-V] {setup,list,app,run} ...
+    usage: smif [-h] [-V]
+                {setup,list,available_results,missing_results,prepare-convert,prepare-scenario,prepare-run,csv2parquet,app,run,before_step,decide,step}
+                ...
 
     Command line tools for smif
 
     positional arguments:
-    {setup,list,app,run}  available commands
+    {setup,list,available_results,missing_results,prepare-convert,prepare-scenario,prepare-run,csv2parquet,app,run,before_step,decide,step}
+                            available commands
         setup               Setup the project folder
         list                List available model runs
+        available_results   List available results
+        missing_results     List missing results
+        prepare-convert     Convert data from one format to another
+        prepare-scenario    Prepare scenario configuration file with multiple
+                            variants
+        prepare-run         Prepare model runs based on scenario variants
+        csv2parquet         Convert CSV to Parquet. Pass a filename or a directory
+                            to search recurisvely
         app                 Open smif app
-        run                 Run a model
+        run                 Run a modelrun
+        before_step         Initialise a model before stepping through
+        decide              Run a decision step
+        step                Run a model step
 
     optional arguments:
     -h, --help            show this help message and exit
@@ -162,6 +176,42 @@ Or, in the app, go to the "Job Runner" screen.
     [D] Click on the down-arrow button to follow the console output as the job runs
 
 
+Run models step-by-step
+-----------------------
+
+Try dry-running a model to see the steps that would be taken, without actually running any
+simulations or decisions::
+
+    $ smif run energy_water_cp_cr --dry-run
+    Dry run, stepping through model run without execution:
+        smif decide energy_water_cp_cr
+        smif before_step energy_water_cp_cr --model energy_demand
+        smif step energy_water_cp_cr --model energy_demand --timestep 2020 --decision 0
+        smif step energy_water_cp_cr --model energy_demand --timestep 2015 --decision 0
+        smif step energy_water_cp_cr --model energy_demand --timestep 2010 --decision 0
+        smif before_step energy_water_cp_cr --model water_supply
+        smif step energy_water_cp_cr --model water_supply --timestep 2010 --decision 0
+        smif step energy_water_cp_cr --model water_supply --timestep 2015 --decision 0
+        smif step energy_water_cp_cr --model water_supply --timestep 2020 --decision 0
+
+Each of these commands can be run individually to step through the simulation.
+
+``smif decide`` first sets up the pre-planned interventions. In another model set-up it would
+run the decision agent - for more details, see decisions_.
+
+``smif before_step`` initialises each model before it is run.
+
+``smif step`` runs a single component of the model for a single timestep, with a single set of
+decisions.
+
+The order of operations matters. In this example, the ``energy_demand`` model must run first
+because it provides outputs to the ``water_supply`` model. The order of timesteps doesn't
+matter for ``energy_demand`` because it calculates demand directly from scenario data. The
+order of timesteps does matter for ``water_supply`` because it calculates and outputs reservoir
+levels at the end of each timestep, which it then reads as an input at the beginning of the
+next timestep.
+
+
 View results
 ------------
 

requirements.txt

@@ -15,6 +15,6 @@ python-dateutil>=2.6
 pywin32; sys_platform == 'win32'
 requests
 Rtree>=0.7
-ruamel.yaml==0.15.50
+ruamel.yaml>=0.15.50
 shapely>=1.3
 xarray

setup.cfg

@@ -31,7 +31,7 @@ package_dir =
 # Add here dependencies of your project (semicolon-separated), e.g.
 # install_requires = numpy; scipy
 # These should match requirements.txt, without the pinned version numbers
-install_requires = flask; isodate; minio; networkx; numpy; Pint; pyarrow; python-dateutil; requests; ruamel.yaml==0.15.50
+install_requires = flask; isodate; minio; networkx; numpy; Pint; pyarrow; python-dateutil; requests; ruamel.yaml>=0.15.50
 # Add here test requirements (semicolon-separated)
 tests_require = pytest; pytest-cov
 

src/smif/cli/__init__.py

@@ -76,7 +76,9 @@
 import pandas
 import smif
 import smif.cli.log
-from smif.controller import copy_project_folder, execute_model_run
+from smif.controller import (copy_project_folder, execute_decision_step,
+                             execute_model_before_step, execute_model_run,
+                             execute_model_step)
 from smif.controller.run import DAFNIRunScheduler, SubProcessRunScheduler
 from smif.data_layer import Store
 from smif.data_layer.file import (CSVDataStore, FileMetadataStore,
@@ -316,7 +318,40 @@ def prepare_model_runs(args):
                              var_start, var_end)
 
 
-def run_model_runs(args):
+def before_step(args):
+    """Prepare a single model to run (call once before calling `smif step`)
+
+    Parameters
+    ----------
+    args
+    """
+    store = _get_store(args)
+    execute_model_before_step(args.modelrun, args.model, store)
+
+
+def step(args):
+    """Run a single model for a single timestep
+
+    Parameters
+    ----------
+    args
+    """
+    store = _get_store(args)
+    execute_model_step(args.modelrun, args.model, args.timestep, args.decision, store)
+
+
+def decide(args):
+    """Run a decision step for a model run
+
+    Parameters
+    ----------
+    args
+    """
+    store = _get_store(args)
+    execute_decision_step(args.modelrun, args.decision, store)
+
+
+def run(args):
     """Run the model runs as requested. Check if results exist and asks
     user for permission to overwrite
 
@@ -325,12 +360,12 @@ def run_model_runs(args):
     args
     """
     logger = logging.getLogger(__name__)
+    msg = '{:s}, {:s}, {:s}'.format(args.modelrun, args.interface, args.directory)
+
     try:
-        logger.profiling_start('run_model_runs', '{:s}, {:s}, {:s}'.format(
-            args.modelrun, args.interface, args.directory))
+        logger.profiling_start('run_model_runs', msg)
     except AttributeError:
-        logger.info('START run_model_runs', '{:s}, {:s}, {:s}'.format(
-            args.modelrun, args.interface, args.directory))
+        logger.info('START run_model_runs %s', msg)
 
     if args.batchfile:
         with open(args.modelrun, 'r') as f:
@@ -339,14 +374,14 @@ def run_model_runs(args):
         model_run_ids = [args.modelrun]
 
     store = _get_store(args)
-    execute_model_run(model_run_ids, store, args.warm)
+    execute_model_run(model_run_ids, store, args.warm, args.dry_run)
+
     try:
-        logger.profiling_stop('run_model_runs', '{:s}, {:s}, {:s}'.format(
-            args.modelrun, args.interface, args.directory))
-        logger.summary()
+        logger.profiling_stop('run_model_runs', msg)
+        if not args.dry_run:
+            logger.summary()
     except AttributeError:
-        logger.info('STOP run_model_runs', '{:s}, {:s}, {:s}'.format(
-            args.modelrun, args.interface, args.directory))
+        logger.info('STOP run_model_runs %s', msg)
 
 
 def _get_store(args):
@@ -559,8 +594,8 @@ def parse_arguments():
 
     # RUN
     parser_run = subparsers.add_parser(
-        'run', help='Run a model', parents=[parent_parser])
-    parser_run.set_defaults(func=run_model_runs)
+        'run', help='Run a modelrun', parents=[parent_parser])
+    parser_run.set_defaults(func=run)
     parser_run.add_argument('-w', '--warm',
                             action='store_true',
                             help="Use intermediate results from the last modelrun \
@@ -571,6 +606,52 @@ def parse_arguments():
                                   list of modelrun names)")
     parser_run.add_argument('modelrun',
                             help="Name of the model run to run")
+    parser_run.add_argument('-n', '--dry-run',
+                            action='store_true',
+                            help="Do not execute individual models, print steps instead")
+
+    # BEFORE RUN
+    parser_before_step = subparsers.add_parser(
+        'before_step',
+        help='Initialise a model before stepping through',
+        parents=[parent_parser])
+    parser_before_step.set_defaults(func=before_step)
+    parser_before_step.add_argument('modelrun',
+                                    help="Name of the model run")
+    parser_before_step.add_argument('-m', '--model',
+                                    required=True,
+                                    help="The individual model to run.")
+
+    # DECIDE
+    parser_decide = subparsers.add_parser(
+        'decide', help='Run a decision step', parents=[parent_parser])
+    parser_decide.set_defaults(func=decide)
+    parser_decide.add_argument('modelrun',
+                               help="Name of the model run")
+    parser_decide.add_argument('-dn', '--decision',
+                               type=int,
+                               default=0,
+                               help="The decision step to run: either 0 to start a run, or "
+                                    "n+1 where n is the maximum previous decision iteration "
+                                    "for which all steps have been simulated")
+
+    # STEP
+    parser_step = subparsers.add_parser(
+        'step', help='Run a model step', parents=[parent_parser])
+    parser_step.set_defaults(func=step)
+    parser_step.add_argument('modelrun',
+                             help="Name of the model run")
+    parser_step.add_argument('-m', '--model',
+                             required=True,
+                             help="The individual model to run.")
+    parser_step.add_argument('-t', '--timestep',
+                             type=int,
+                             required=True,
+                             help="The single timestep to run.")
+    parser_step.add_argument('-dn', '--decision',
+                             type=int,
+                             required=True,
+                             help="The decision step to run.")
 
     return parser
 
@@ -646,7 +727,7 @@ def exception_handler(exception_type, exception, traceback, debug_hook=sys.excep
         if args.verbose:
             debug_hook(exception_type, exception, traceback)
         else:
-            print("{}: {}".format(exception_type.__name__, exception))
+            print("{}: {}".format(exception_type.__name__, exception), file=sys.stderr)
 
     sys.excepthook = exception_handler
     if 'func' in args:

src/smif/cli/log.py

@@ -44,8 +44,8 @@ def summary(self, *args, **kws):
             profile_data = logging.Logger._profile[profile]
             diff = profile_data['stop'] - profile_data['start']
             s = diff.total_seconds()
-            time_spent = '{:02d}:{:02d}:{:02d}'.format(
-                int(s // 3600), int(s % 3600 // 60), int(s % 60))
+            time_spent = '{:02d}:{:02d}:{:05.2f}'.format(
+                int(s // 3600), int(s % 3600 // 60), s % 60)
 
             # trunctuate long lines
             if len(profile[0]) > columns[0]-2:
@@ -96,7 +96,11 @@ def setup_logging(loglevel):
         'root': {
             'handlers': ['file', 'stream'],
             'level': 'DEBUG'
-        }
+        },
+        # disable_existing_loggers defaults to True, which causes problems with class/module
+        # -specific loggers, especially in unit tests when this method might be called multiple
+        # times
+        'disable_existing_loggers': False
     }
 
     if loglevel is None:

src/smif/controller/__init__.py

@@ -36,10 +36,14 @@
 
 # import classes for access like ::
 #         from smif.controller import ModelRunner
-from smif.controller.execute import execute_model_run
-from smif.controller.setup import copy_project_folder
+from smif.controller.execute_run import execute_model_run
+from smif.controller.execute_step import (execute_decision_step,
+                                          execute_model_before_step,
+                                          execute_model_step)
 from smif.controller.modelrun import ModelRunner
+from smif.controller.setup import copy_project_folder
 
 # Define what should be imported as * ::
 #         from smif.controller import *
-__all__ = ['ModelRunner', 'execute_model_run', 'copy_project_folder']
+__all__ = ['ModelRunner', 'execute_decision_step', 'execute_model_before_step',
+           'execute_model_run', 'execute_model_step', 'copy_project_folder']

src/smif/controller/build.py

@@ -4,9 +4,8 @@
 import traceback
 
 from smif.controller.modelrun import ModelRun
-from smif.data_layer.model_loader import ModelLoader
 from smif.exception import SmifDataNotFoundError
-from smif.model import ScenarioModel, SosModel
+from smif.model import ScenarioModel, SectorModel, SosModel
 
 
 def get_model_run_definition(store, modelrun):
@@ -96,15 +95,14 @@ def get_sector_models(sector_model_names, handler):
     list of SectorModel implementations
     """
     sector_models = []
-    loader = ModelLoader()
     for sector_model_name in sector_model_names:
         sector_model_config = handler.read_model(sector_model_name)
 
         # absolute path to be crystal clear for ModelLoader when loading python class
         sector_model_config['path'] = os.path.normpath(
             os.path.join(handler.model_base_folder, sector_model_config['path'])
         )
-        sector_model = loader.load(sector_model_config)
+        sector_model = SectorModel.from_dict(sector_model_config)
         sector_models.append(sector_model)
     return sector_models
 
@@ -125,7 +123,7 @@ def build_model_run(model_run_config):
     try:
         logger.profiling_start('build_model_run', model_run_config['name'])
     except AttributeError:
-        logger.info('build_model_run', model_run_config['name'])
+        logger.info('build_model_run %s', model_run_config['name'])
 
     try:
         model_run = ModelRun.from_dict(model_run_config)
@@ -142,5 +140,5 @@ def build_model_run(model_run_config):
     try:
         logger.profiling_stop('build_model_run', model_run_config['name'])
     except AttributeError:
-        logger.info('build_model_run', model_run_config['name'])
+        logger.info('build_model_run %s', model_run_config['name'])
     return model_run