diff --git a/logging_tutorial.rst b/logging_tutorial.rst new file mode 100644 index 00000000..0be59ee5 --- /dev/null +++ b/logging_tutorial.rst @@ -0,0 +1,99 @@ +Logging tutorial +================ + +While running the model, it is sometimes useful to monitor the progress +of certain characteristics across time. This can be used, for instance, +when debugging or to verify that a recent change has had the desired behaviour. + +This can be achieved by modifying the ``LOGGING`` section of the configuration +that is passed to the simulation tool. + +Logging configuration +--------------------- +**TODO:** Explain the basic options (directory, prefix, level) + +Specifying what to log +---------------------- +By default, no variables are logged. To control which variables will be included, +list them under the ``column`` key in the logging configuration. + +For example, the following configuration will print the values of the ``age`` +and ``sex`` columns for the whole population at every time step: + +.. code-block:: yaml + :caption: Basic logging configuration + + LOGGING: + log_directory: log + logfile_prefix: hivpy + log_file_level: DEBUG + console_log_level: WARNING + columns: [age, sex] + +If any of the columns are not recognised (because of a misspelling, for example), +the log will display a warning at the start of the simulation, but the simulation +will run as normal (with that column name ignored in the log output). + +Selecting a subpopulation +------------------------- +Instead of showing values for the whole population, you can select a subset to monitor. +This can be done with the ``if`` key and by providing the criteria for selecting +the subset of interest. + +For example, this configuration will only log values for female individuals: + +.. code-block:: yaml + :caption: Selecting by a single variable + + LOGGING: + log_directory: log + logfile_prefix: hivpy + log_file_level: DEBUG + console_log_level: WARNING + columns: [age, sex] + if: + sex: female + + +Multiple variables can be specified at the same time by providing more keys to ``if``. +For instance, to select male, HIV- individuals: + +.. code-block:: yaml + :caption: Selecting by multiple variable + + LOGGING: + log_directory: log + logfile_prefix: hivpy + log_file_level: DEBUG + console_log_level: WARNING + columns: [age, sex] + if: + sex: male + hiv: False + + +The examples so far have been matching on exact values (such as ``female`` or ``False``), +but often we want to match a range of values, particularly for numerical variables. +To do this, use one of these special keys: + +* ``eq``: equal to the value provided +* ``lt``: less than the value provided +* ``gt``: greater than the value provided +* ``lte``, ``gte``: as above but also allowing equality + + +The configuration below selects female, HIV+ individuals between 23 and 30 years old +(both inclusive): + +.. code-block:: yaml + :caption: More complex criteria + + LOGGING: + # (the other configuration keys are omitted for brevity) + if: + sex: female + hiv: True + age: + gte: 23 + lte: 30 + diff --git a/src/hivpy/config.py b/src/hivpy/config.py index 5d2714de..8301393b 100644 --- a/src/hivpy/config.py +++ b/src/hivpy/config.py @@ -1,19 +1,9 @@ -import logging from dataclasses import dataclass from datetime import date, timedelta -from os import path from pathlib import Path from .exceptions import SimulationException -LEVELS = { - 'DEBUG': logging.DEBUG, - 'INFO': logging.INFO, - 'WARNING': logging.WARNING, - 'ERROR': logging.ERROR, - 'CRITICAL': logging.CRITICAL -} - @dataclass class LoggingConfig: @@ -24,25 +14,6 @@ class LoggingConfig: fileLogging: bool = True fileLogLevel: str = 'DEBUG' - def start_logging(self): - # file logging - file = path.join(self.log_dir, self.logfile) - logging.root.setLevel(logging.DEBUG) - file_logger = logging.FileHandler(file, 'w') - file_formatter = logging.Formatter('%(asctime)s %(name)-15s %(levelname)-10s %(message)s', - datefmt='%y-%d-%m %H:%M:%S') - file_logger.setFormatter(file_formatter) - file_logger.setLevel(self.fileLogLevel) - logging.getLogger(name=None).addHandler(file_logger) - # console logging - console_logger = logging.StreamHandler() - console_formatter = logging.Formatter('%(name)-15s %(levelname)-10s %(message)s') - console_logger.setFormatter(console_formatter) - console_logger.setLevel(self.consoleLogLevel) - logging.getLogger(name=None).addHandler(console_logger) - - print("Starting the simulation. Please, consult the logfile at "+self.logfile) - @dataclass class SimulationConfig: diff --git a/src/hivpy/demographics.py b/src/hivpy/demographics.py index e45beea9..54aa11ba 100644 --- a/src/hivpy/demographics.py +++ b/src/hivpy/demographics.py @@ -1,5 +1,4 @@ import importlib.resources -import logging from math import exp import numpy as np @@ -10,6 +9,7 @@ from hivpy.common import SexType, rng from hivpy.demographics_data import DemographicsData from hivpy.exceptions import SimulationException +from hivpy.logging import get_logger SexDType = pd.CategoricalDtype(iter(SexType)) @@ -117,9 +117,9 @@ def __init__(self, min_age, max_age, modelParams): self.min_age = min_age model_age_limit = -modelParams[1]/modelParams[0] if (max_age > model_age_limit): - logging.getLogger("Demographics").warning(f"Max age exceeds the maximum age limit for " - f"this model (negative probability). " - f"Adjusting max age to {model_age_limit}") + get_logger("Demographics").warning(f"Max age exceeds the maximum age limit for " + f"this model (negative probability). " + f"Adjusting max age to {model_age_limit}") self.max_age = model_age_limit else: self.max_age = max_age diff --git a/src/hivpy/experiment.py b/src/hivpy/experiment.py index 88b3cea7..90960813 100644 --- a/src/hivpy/experiment.py +++ b/src/hivpy/experiment.py @@ -7,6 +7,7 @@ from .config import ExperimentConfig, LoggingConfig, SimulationConfig from .exceptions import OutputException +from .logging import start_logging from .simulation import SimulationHandler @@ -88,13 +89,13 @@ def create_experiment(all_params): return ExperimentConfig(simulation_config, logging_config) -def run_experiment(experiment_config): +def run_experiment(experiment_config: ExperimentConfig): """Run an entire experiment. An experiment can consist of one or more simulation runs, as well as processing steps after those are completed. """ - experiment_config.logging_config.start_logging() + start_logging(experiment_config.logging_config) simulation_handler = SimulationHandler(experiment_config.simulation_config) simulation_handler.run() return (simulation_handler.population) diff --git a/src/hivpy/logging.py b/src/hivpy/logging.py new file mode 100644 index 00000000..f402779b --- /dev/null +++ b/src/hivpy/logging.py @@ -0,0 +1,50 @@ +import logging +from os import path + +from .config import LoggingConfig + +LEVELS = { + 'DEBUG': logging.DEBUG, + 'INFO': logging.INFO, + 'WARNING': logging.WARNING, + 'ERROR': logging.ERROR, + 'CRITICAL': logging.CRITICAL +} + +_ROOT_NAME = "hivpy" + + +def start_logging(config: LoggingConfig): + root_logger = logging.getLogger(name=_ROOT_NAME) + + # file logging + file = path.join(config.log_dir, config.logfile) + root_logger.setLevel(logging.DEBUG) + file_logger = logging.FileHandler(file, 'w') + file_formatter = logging.Formatter('%(asctime)s %(name)-15s %(levelname)-10s %(message)s', + datefmt='%y-%d-%m %H:%M:%S') + file_logger.setFormatter(file_formatter) + file_logger.setLevel(config.fileLogLevel) + root_logger.addHandler(file_logger) + # console logging + console_logger = logging.StreamHandler() + console_formatter = logging.Formatter('%(name)-15s %(levelname)-10s %(message)s') + console_logger.setFormatter(console_formatter) + console_logger.setLevel(config.consoleLogLevel) + root_logger.addHandler(console_logger) + + print("Starting the simulation. Please, consult the logfile at "+config.logfile) + + +def get_logger(name=None): + qualified_logger_name = _ROOT_NAME + (f".{name.lower()}" if name else "") + return logging.getLogger(qualified_logger_name) + + +class HIVpyLogger: + def __init__(self, base_logger=None): + self._logger = base_logger if base_logger is not None else get_logger() + + def write_population(self, population): + population # stand-in to satisfy linter + self._logger.info("This is where the population will go.") diff --git a/src/hivpy/simulation.py b/src/hivpy/simulation.py index 0c4b1d38..def49104 100644 --- a/src/hivpy/simulation.py +++ b/src/hivpy/simulation.py @@ -1,4 +1,3 @@ -import logging import operator from datetime import datetime @@ -7,6 +6,7 @@ from .common import SexType, selector from .config import SimulationConfig +from .logging import HIVpyLogger, get_logger from .population import Population @@ -100,16 +100,19 @@ def _initialise_population(self): self.population = Population(self.simulation_config.population_size, self.simulation_config.start_date) - def run(self): + def run(self, pop_logger: HIVpyLogger = None): + logger = get_logger() # Start the simulation date = self.simulation_config.start_date assert date == self.population.date time_step = self.simulation_config.time_step while date <= self.simulation_config.stop_date: - logging.info("Timestep %s\n", date) + logger.info("Timestep %s\n", date) # Advance the population self.population = self.population.evolve(time_step) + if pop_logger: + pop_logger.write_population(self.population) self.output.update_summary_stats(date, self.population.data) date = date + time_step - logging.info("finished") + logger.info("finished") self.output.write_output(self.output_path) diff --git a/src/tests/test_logging.py b/src/tests/test_logging.py index 8280a094..ad2aeeda 100644 --- a/src/tests/test_logging.py +++ b/src/tests/test_logging.py @@ -1,15 +1,15 @@ -import logging import os.path as path from hivpy.config import LoggingConfig +from hivpy.logging import get_logger, start_logging def test_logging_levels(tmp_path, capsys): d = tmp_path / "log" d.mkdir() log_cfg = LoggingConfig(log_dir=d, logfile="hivpy.log") - log_cfg.start_logging() - logger = logging.getLogger("Testing") + start_logging(log_cfg) + logger = get_logger("Testing") TEST_DEBUG = "Test debug." TEST_INFO = "Test info." TEST_WARNING = "Test warning."