Skip to content

Commit

Permalink
Update logging and include examples (#492)
Browse files Browse the repository at this point in the history
  • Loading branch information
brynpickering authored Oct 24, 2023
1 parent b2e7530 commit 51c0872
Show file tree
Hide file tree
Showing 17 changed files with 527 additions and 118 deletions.
1 change: 1 addition & 0 deletions .github/workflows/pr-ci.yml
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@ concurrency:

jobs:
test:
if: github.event.pull_request.draft == false
strategy:
matrix:
os: [ubuntu-latest]
Expand Down
1 change: 1 addition & 0 deletions .gitignore
Original file line number Diff line number Diff line change
Expand Up @@ -29,3 +29,4 @@ dist/
doc/_build/
doc/_static/notebooks/*.html
.ipynb_checkpoints
outputs/
286 changes: 286 additions & 0 deletions doc/_static/notebooks/logging.ipynb
Original file line number Diff line number Diff line change
@@ -0,0 +1,286 @@
{
"cells": [
{
"cell_type": "markdown",
"metadata": {},
"source": [
"# Calliope logging examples\n",
"\n",
"In this notebook, we will look at ways of capturing calliope logging outputs and printing them to the console or to file."
]
},
{
"cell_type": "code",
"execution_count": null,
"metadata": {},
"outputs": [],
"source": [
"import logging\n",
"from pathlib import Path\n",
"\n",
"import calliope"
]
},
{
"cell_type": "markdown",
"metadata": {},
"source": [
"## Using internal Calliope functionality\n",
"The `calliope.set_log_verbosity` method allows you to quickly set the logging level across all calliope loggers.\n",
"It doesn't require you to know anything about the `logging` package, just the available [logging levels](https://docs.python.org/3/library/logging.html#logging-levels)."
]
},
{
"cell_type": "code",
"execution_count": null,
"metadata": {},
"outputs": [],
"source": [
"# This is the default log verbosity that is set on importing calliope.\n",
"# It will print the WARNING and INFO log levels to the console\n",
"# and it will print the solver output (which is otherwise at the DEBUG log level)\n",
"calliope.set_log_verbosity(\"info\")\n",
"m = calliope.examples.national_scale()\n",
"m.build()\n",
"m.solve()"
]
},
{
"cell_type": "code",
"execution_count": null,
"metadata": {},
"outputs": [],
"source": [
"# This will print WARNING and INFO log levels to the console but *NOT* the log solver output\n",
"calliope.set_log_verbosity(\"info\", include_solver_output=False)\n",
"m = calliope.examples.national_scale()\n",
"m.build()\n",
"m.solve()"
]
},
{
"cell_type": "code",
"execution_count": null,
"metadata": {},
"outputs": [],
"source": [
"# You can set the log verbosity to print all DEBUG level logs to the console\n",
"calliope.set_log_verbosity(\"debug\")\n",
"m = calliope.examples.national_scale()\n",
"m.build()\n",
"m.solve()"
]
},
{
"cell_type": "markdown",
"metadata": {},
"source": [
"## Adding your own console logging handler\n",
"If the `calliope.set_log_verbosity` method isn't providing you with enough flexibility then you can add your own logging `handlers`"
]
},
{
"cell_type": "code",
"execution_count": null,
"metadata": {},
"outputs": [],
"source": [
"# Grab the calliope logger, which will also automatically all the child loggers (e.g., `calliope.core.model`).\n",
"logger = logging.getLogger(\"calliope\")\n",
"\n",
"# Remove existing handlers (i.e., those introduced by `calliope.set_log_verbosity` above)\n",
"logger.handlers.clear()\n",
"\n",
"# You can define your own custom formatter.\n",
"# See https://docs.python.org/3/library/logging.html#logrecord-attributes for available attributes.\n",
"formatter = logging.Formatter(\"%(asctime)s - %(name)s - %(levelname)s - %(message)s\")\n",
"\n",
"# Add a ConsoleHandler (this is what `calliope.set_log_verbosity` is doing under the hood)\n",
"console_handler = logging.StreamHandler()\n",
"console_handler.setLevel(\n",
" logging.INFO\n",
") # In this example, we only want to see warnings in the console\n",
"console_handler.setFormatter(formatter)\n",
"logger.addHandler(console_handler)\n",
"\n",
"# You can also use logging in your scripts to add more information\n",
"logger.info(\"Loading the national-scale example model\")\n",
"m = calliope.examples.national_scale()\n",
"\n",
"logger.info(\"Building the national-scale example model optimisation problem\")\n",
"m.build()\n",
"\n",
"logger.info(\"Solving the national-scale example model optimisation problem\")\n",
"m.solve()"
]
},
{
"cell_type": "markdown",
"metadata": {},
"source": [
"## Adding your own file logging handler\n",
"You may find it more practical to store logging information in files, particularly if you are running your model on a remote device or if you have a *very* large model.\n",
"\n",
"Then, you can search through your logs using your favourite IDE."
]
},
{
"cell_type": "code",
"execution_count": null,
"metadata": {},
"outputs": [],
"source": [
"# Grab the calliope logger, which will also automatically all the child loggers (e.g., `calliope.core.model`).\n",
"logger = logging.getLogger(\"calliope\")\n",
"\n",
"# Remove existing handlers (i.e., those introduced earlier in this notebook)\n",
"logger.handlers.clear()\n",
"\n",
"# You can define your own custom formatter.\n",
"# See https://docs.python.org/3/library/logging.html#logrecord-attributes for available attributes.\n",
"formatter = logging.Formatter(\"%(asctime)s - %(name)s - %(levelname)s - %(message)s\")\n",
"\n",
"log_filepath = Path(\".\") / \"outputs\"\n",
"log_filepath.mkdir(parents=True, exist_ok=True)\n",
"\n",
"# Set up a file handler, which will store log outputs in a file\n",
"file_handler = logging.FileHandler(log_filepath / \"calliope.log\")\n",
"file_handler.setLevel(logging.DEBUG)\n",
"file_handler.setFormatter(formatter)\n",
"logger.addHandler(file_handler)\n",
"\n",
"# You can also use logging in your scripts to add more information\n",
"logger.info(\"Loading the national-scale example model\")\n",
"m = calliope.examples.national_scale()\n",
"\n",
"logger.info(\"Building the national-scale example model optimisation problem\")\n",
"m.build()\n",
"\n",
"logger.info(\"Solving the national-scale example model optimisation problem\")\n",
"m.solve()"
]
},
{
"cell_type": "markdown",
"metadata": {},
"source": [
"Notice that there is no logging to the console here, but that there is now a file `outputs/calliope.log` that contains the logging information.\n",
"\n",
"We can also log both to the console at one level and to file at another:"
]
},
{
"cell_type": "code",
"execution_count": null,
"metadata": {},
"outputs": [],
"source": [
"# Grab the calliope logger, which will also automatically all the child loggers (e.g., `calliope.core.model`).\n",
"logger = logging.getLogger(\"calliope\")\n",
"\n",
"# Remove existing handlers (i.e., those introduced earlier in this notebook)\n",
"logger.handlers.clear()\n",
"\n",
"# You can define your own custom formatter.\n",
"# See https://docs.python.org/3/library/logging.html#logrecord-attributes for available attributes.\n",
"formatter = logging.Formatter(\"%(asctime)s - %(name)s - %(levelname)s - %(message)s\")\n",
"\n",
"# Add a ConsoleHandler (this is what `calliope.set_log_verbosity` is doing under the hood)\n",
"console_handler = logging.StreamHandler()\n",
"# Log to console at the INFO level\n",
"console_handler.setLevel(logging.INFO)\n",
"console_handler.setFormatter(formatter)\n",
"logger.addHandler(console_handler)\n",
"\n",
"log_filepath = Path(\".\") / \"outputs\"\n",
"log_filepath.mkdir(parents=True, exist_ok=True)\n",
"\n",
"# Set up a file handler, which will store log outputs in a file\n",
"file_handler = logging.FileHandler(log_filepath / \"calliope.log\")\n",
"# Log to file at the DEBUG level\n",
"file_handler.setLevel(logging.DEBUG)\n",
"file_handler.setFormatter(formatter)\n",
"logger.addHandler(file_handler)\n",
"\n",
"# You can also use logging in your scripts to add more information\n",
"logger.info(\"Loading the national-scale example model\")\n",
"m = calliope.examples.national_scale()\n",
"\n",
"logger.info(\"Building the national-scale example model optimisation problem\")\n",
"m.build()\n",
"\n",
"logger.info(\"Solving the national-scale example model optimisation problem\")\n",
"m.solve()"
]
},
{
"cell_type": "markdown",
"metadata": {},
"source": [
"The log file will contain all calliope child logger outputs in one place.\n",
"You will notice the name of the logger, which corresponds to the file where the log was recorded, at the second level of the log messages.\n",
"\n",
"We can store each of these child loggers to a different file if we like:"
]
},
{
"cell_type": "code",
"execution_count": null,
"metadata": {},
"outputs": [],
"source": [
"# Grab the calliope logger, which will also automatically all the child loggers (e.g., `calliope.core.model`).\n",
"logger = logging.getLogger(\"calliope\")\n",
"\n",
"# Remove existing handlers (i.e., those introduced earlier in this notebook)\n",
"logger.handlers.clear()\n",
"\n",
"# You can define your own custom formatter.\n",
"# Here we don't include the logger name, as the filename will contain that information.\n",
"# See https://docs.python.org/3/library/logging.html#logrecord-attributes for available attributes.\n",
"formatter = logging.Formatter(\"%(asctime)s - %(levelname)s - %(message)s\")\n",
"\n",
"log_filepath = Path(\".\") / \"outputs\"\n",
"log_filepath.mkdir(parents=True, exist_ok=True)\n",
"\n",
"for logger_name in logging.root.manager.loggerDict.keys():\n",
" if not logger_name.startswith(\"calliope\"):\n",
" # There are lots of other loggers that calliope imports from its dependencies which we will ignore.\n",
" # You can also dump these log to files if you like, by removing this conditional statement.\n",
" continue\n",
" # Set up a file handler, which will store log outputs in a file\n",
" file_handler = logging.FileHandler(log_filepath / f\"{logger_name}.log\")\n",
" # Log to file at the DEBUG level\n",
" file_handler.setLevel(logging.DEBUG)\n",
" file_handler.setFormatter(formatter)\n",
" logging.getLogger(logger_name).addHandler(file_handler)\n",
"\n",
"m = calliope.examples.national_scale()\n",
"m.build()\n",
"m.solve()"
]
}
],
"metadata": {
"kernelspec": {
"display_name": "Python 3",
"language": "python",
"name": "python3"
},
"language_info": {
"codemirror_mode": {
"name": "ipython",
"version": 3
},
"file_extension": ".py",
"mimetype": "text/x-python",
"name": "python",
"nbconvert_exporter": "python",
"pygments_lexer": "ipython3",
"version": "3.11.5"
},
"orig_nbformat": 4
},
"nbformat": 4,
"nbformat_minor": 2
}
10 changes: 9 additions & 1 deletion doc/conf.py
Original file line number Diff line number Diff line change
Expand Up @@ -103,7 +103,15 @@

# Mock modules for Read The Docs autodoc generation

MOCK_MODULES = ["xarray", "pandas", "numpy", "pyomo", "sklearn", "pyparsing", "netCDF4"]
MOCK_MODULES = [
"xarray",
"pandas",
"numpy",
"pyomo",
"sklearn",
"pyparsing",
"netCDF4",
]
autodoc_mock_imports = MOCK_MODULES
autodoc_typehints = "both"
autodoc_member_order = "bysource"
Expand Down
27 changes: 23 additions & 4 deletions doc/user/troubleshooting.rst
Original file line number Diff line number Diff line change
Expand Up @@ -151,12 +151,31 @@ Particularly if your problem is large, you may not want to rebuild the backend t
Debugging model errors
----------------------

Calliope provides a method to save its fully built and commented internal representation of a model to a single YAML file with :python:`Model.save_commented_model_yaml(path)`. Comments in the resulting YAML file indicate where original values were overridden.
Inspecting debug logs
^^^^^^^^^^^^^^^^^^^^^
At the `debug` logging level, we output a lot of information about your model build which may be useful to inspect.
You can do so by setting :python:`calliope.set_log_verbosity("debug")` and then running your model.

Because this is Calliope's internal representation of a model directly before the ``model_data`` ``xarray.Dataset`` is built, it can be useful for debugging possible issues in the model formulation, for example, undesired constraints that exist at specific locations because they were specified model-wide without having been superseded by location-specific settings.
If you have a bit more Python experience, you can also consider accessing and working with loggers at different points in our internals using the `logging` package.

Further processing of the data does occur before solving the model. The final values of parameters used by the backend solver to generate constraints can be analysed when running an interactive Python session by running :python:`model.backend.get_input_params()`. This provides a user with an xarray Dataset which will look very similar to :python:`model.inputs`, except that assumed :ref:`default values <defaults>` will be included. An attempt at running the model has to be made in order to be able to run this command.
- For input YAML and CSV file processing: :python:`logging.getLogger("calliope.preprocess")`.
- For processing of math syntax: :python:`logging.getLogger("calliope.backend")`.

For more examples of using loggers, see :nbviewer_docs:`this notebook <_static/notebooks/logging.ipynb>`.

Validating your math syntax
^^^^^^^^^^^^^^^^^^^^^^^^^^^
You can do a (relatively) quick check of the validity of any custom math syntax in your model by running :python:`model.validate_math_strings(my_math_dict)`.
This will tell you if any of the syntax is malformed, although it cannot tell you if the model will build when set to the backend to generate an optimisation model.

Inspecting private data structures
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
There are private attributes of the Calliope `Model` object that you can access to gain additional insights into your model runs.

- For the result of processing your input YAML files, the dictionary :python:`model._model_run`.
- For all data variables in one place (i.e., the combination of `inputs` and `results`), the dataset :python:`model._model_data`.
- For the build backend objects (e.g., Pyomo objects) in an array format, the dataset :python:`model.backend._dataset`.

.. seealso::

If using Calliope interactively in a Python session, we recommend reading up on the `Python debugger <https://docs.python.org/3/library/pdb.html>`_ and (if using Jupyter notebooks) making use of the `%debug magic <https://ipython.readthedocs.io/en/stable/interactive/magics.html#magic-debug>`_.
If using Calliope interactively in a Python session, we recommend reading up on the `Python debugger <https://docs.python.org/3/library/pdb.html>`_ and making use of the `%debug magic <https://ipython.readthedocs.io/en/stable/interactive/magics.html#magic-debug>`_.
Loading

0 comments on commit 51c0872

Please sign in to comment.