Calliope logging examples¶

In this notebook, we will look at ways of capturing calliope logging outputs and printing them to the console or to file.

In [1]:

Copied!

import logging
from pathlib import Path

import calliope
import logging
from pathlib import Path

import calliope

Using internal Calliope functionality¶

The calliope.set_log_verbosity method allows you to quickly set the logging level across all calliope loggers. It doesn't require you to know anything about the logging package, just the available logging levels.

This is the default log verbosity that is set on importing calliope. It will print the WARNING and INFO log levels to the console and it will print the solver output (which is otherwise at the DEBUG log level)

In [2]:

Copied!





calliope.set_log_verbosity("info")
m = calliope.examples.national_scale(time_subset=["2005-01-01", "2005-01-01"])
m.build()
m.solve()
calliope.set_log_verbosity("info")
m = calliope.examples.national_scale(time_subset=["2005-01-01", "2005-01-01"])
m.build()
m.solve()

[2024-12-16 11:49:40] INFO     Model: initialising

[2024-12-16 11:49:40] INFO     Model: preprocessing stage 1 (model_run)

[2024-12-16 11:49:43] INFO     Model: preprocessing stage 2 (model_data)

[2024-12-16 11:49:43] INFO     Model: preprocessing complete

[2024-12-16 11:49:43] INFO     Model: backend build starting

[2024-12-16 11:49:43] INFO     Math preprocessing | added file 'plan'.

[2024-12-16 11:49:43] INFO     Math preprocessing | validated math against schema.

[2024-12-16 11:49:43] INFO     Optimisation Model | parameters | Generated.

[2024-12-16 11:49:46] INFO     Optimisation Model | Validated math strings.

[2024-12-16 11:49:46] INFO     Optimisation Model | variables | Generated.

[2024-12-16 11:49:47] INFO     Optimisation Model | global_expressions | Generated.

[2024-12-16 11:49:49] INFO     Optimisation Model | constraints | Generated.

[2024-12-16 11:49:49] INFO     Optimisation Model | piecewise_constraints | Generated.

[2024-12-16 11:49:49] INFO     Optimisation Model | objectives | Generated.

[2024-12-16 11:49:49] INFO     Model: backend build complete

[2024-12-16 11:49:49] INFO     Optimisation model | starting model in plan mode.

[2024-12-16 11:49:49] DEBUG    Welcome to the CBC MILP Solver 
Version: 2.10.12 
Build Date: Sep  3 2024 

command line - /home/docs/checkouts/readthedocs.org/user_builds/calliope/conda/v0.7.0.dev5/bin/cbc -printingOptions all -import /tmp/tmpnrohos_g.pyomo.lp -stat=1 -solve -solu /tmp/tmpnrohos_g.pyomo.soln (default strategy 1)
Option for printingOptions changed from normal to all
Presolve 700 (-583) rows, 861 (-177) columns and 2384 (-1088) elements
Statistics for presolved model


Problem has 700 rows, 861 columns (399 with objective) and 2384 elements
There are 240 singletons with objective 
Column breakdown:
732 of type 0.0->inf, 9 of type 0.0->up, 0 of type lo->inf, 
0 of type lo->up, 0 of type free, 0 of type fixed, 
120 of type -inf->0.0, 0 of type -inf->up, 0 of type 0.0->1.0 
Row breakdown:
224 of type E 0.0, 0 of type E 1.0, 0 of type E -1.0, 
48 of type E other, 0 of type G 0.0, 0 of type G 1.0, 
0 of type G other, 428 of type L 0.0, 0 of type L 1.0, 
0 of type L other, 0 of type Range 0.0->1.0, 0 of type Range other, 
0 of type Free 
Presolve 700 (-583) rows, 861 (-177) columns and 2384 (-1088) elements
Perturbing problem by 0.001% of 66.616365 - largest nonzero change 0.00016650948 ( 19.901606%) - largest zero change 0.00016401159
0  Obj 0 Primal inf 708537.92 (48)
89  Obj 64.743123 Primal inf 754880.64 (48)
178  Obj 5172.2946 Primal inf 1817673 (91)
267  Obj 24242.276 Primal inf 1092822.4 (156)
356  Obj 36907.542 Primal inf 167562.17 (121)
445  Obj 39158.214 Primal inf 1.4289021 (15)
460  Obj 39158.345
Optimal - objective value 38988.744
After Postsolve, objective 38988.744, infeasibilities - dual 0 (0), primal 0 (0)
Optimal objective 38988.7442 - 460 iterations time 0.022, Presolve 0.00
Total time (CPU seconds):       0.04   (Wallclock seconds):       0.02

[2024-12-16 11:49:50] INFO     Backend: solver finished running. Time since start of solving optimisation problem: 0:00:00.257709

[2024-12-16 11:49:50] WARNING  Postprocessing: All values < 1e-10 set to 0 in flow_cap

[2024-12-16 11:49:50] INFO     Postprocessing: ended. Time since start of solving optimisation problem: 0:00:00.382491

[2024-12-16 11:49:50] INFO     Backend: model solve completed. Time since start of solving optimisation problem: 0:00:00.385640

This will print WARNING and INFO log levels to the console but NOT the log solver output

In [3]:

Copied!





calliope.set_log_verbosity("info", include_solver_output=False)
m = calliope.examples.national_scale(time_subset=["2005-01-01", "2005-01-01"])
m.build()
m.solve()
calliope.set_log_verbosity("info", include_solver_output=False)
m = calliope.examples.national_scale(time_subset=["2005-01-01", "2005-01-01"])
m.build()
m.solve()

[2024-12-16 11:49:50] INFO     Model: initialising

[2024-12-16 11:49:50] INFO     Model: preprocessing stage 1 (model_run)

[2024-12-16 11:49:52] INFO     Model: preprocessing stage 2 (model_data)

[2024-12-16 11:49:52] INFO     Model: preprocessing complete

[2024-12-16 11:49:52] INFO     Model: backend build starting

[2024-12-16 11:49:52] INFO     Math preprocessing | added file 'plan'.

[2024-12-16 11:49:53] INFO     Math preprocessing | validated math against schema.

[2024-12-16 11:49:53] INFO     Optimisation Model | parameters | Generated.

[2024-12-16 11:49:56] INFO     Optimisation Model | Validated math strings.

[2024-12-16 11:49:56] INFO     Optimisation Model | variables | Generated.

[2024-12-16 11:49:57] INFO     Optimisation Model | global_expressions | Generated.

[2024-12-16 11:49:59] INFO     Optimisation Model | constraints | Generated.

[2024-12-16 11:49:59] INFO     Optimisation Model | piecewise_constraints | Generated.

[2024-12-16 11:49:59] INFO     Optimisation Model | objectives | Generated.

[2024-12-16 11:49:59] INFO     Model: backend build complete

[2024-12-16 11:49:59] INFO     Optimisation model | starting model in plan mode.

[2024-12-16 11:49:59] INFO     Backend: solver finished running. Time since start of solving optimisation problem: 0:00:00.261337

[2024-12-16 11:49:59] WARNING  Postprocessing: All values < 1e-10 set to 0 in flow_cap

[2024-12-16 11:49:59] INFO     Postprocessing: ended. Time since start of solving optimisation problem: 0:00:00.383795

[2024-12-16 11:49:59] INFO     Backend: model solve completed. Time since start of solving optimisation problem: 0:00:00.386583

You can set the log verbosity to print all DEBUG level logs to the console

In [4]:

Copied!





calliope.set_log_verbosity("debug")
m = calliope.examples.national_scale(time_subset=["2005-01-01", "2005-01-01"])
m.build()
m.solve()
calliope.set_log_verbosity("debug")
m = calliope.examples.national_scale(time_subset=["2005-01-01", "2005-01-01"])
m.build()
m.solve()

[2024-12-16 11:49:59] INFO     Model: initialising

[2024-12-16 11:49:59] INFO     Model: preprocessing stage 1 (model_run)

[2024-12-16 11:49:59] DEBUG    (data_tables, time_varying_parameters) | Updating non-NaN values of parameter `sink_use_equals` to float type.

[2024-12-16 11:49:59] DEBUG    (data_tables, time_varying_parameters) | Updating non-NaN values of parameter `source_use_max` to float type.

[2024-12-16 11:49:59] DEBUG    (data_tables, time_varying_parameters) | Loaded arrays:
<xarray.Dataset> Size: 1MB
Dimensions:          (timesteps: 8760, nodes: 5, techs: 2)
Coordinates:
  * timesteps        (timesteps) object 70kB '2005-01-01 00:00' ... '2005-12-...
  * nodes            (nodes) object 40B 'region1' 'region1_1' ... 'region2'
  * techs            (techs) object 16B 'csp' 'demand_power'
Data variables:
    sink_use_equals  (timesteps, nodes, techs) float64 701kB nan ... 2.295e+03
    source_use_max   (timesteps, nodes, techs) float64 701kB nan nan ... nan nan.

[2024-12-16 11:49:59] DEBUG    (data_tables, cost_parameters) | Updating non-NaN values of parameter `cost_area_use` to float type.

[2024-12-16 11:49:59] DEBUG    (data_tables, cost_parameters) | Updating non-NaN values of parameter `cost_flow_cap` to float type.

[2024-12-16 11:49:59] DEBUG    (data_tables, cost_parameters) | Updating non-NaN values of parameter `cost_flow_in` to float type.

[2024-12-16 11:49:59] DEBUG    (data_tables, cost_parameters) | Updating non-NaN values of parameter `cost_flow_out` to float type.

[2024-12-16 11:49:59] DEBUG    (data_tables, cost_parameters) | Updating non-NaN values of parameter `cost_source_cap` to float type.

[2024-12-16 11:49:59] DEBUG    (data_tables, cost_parameters) | Updating non-NaN values of parameter `cost_storage_cap` to float type.

[2024-12-16 11:49:59] DEBUG    (data_tables, cost_parameters) | Loaded arrays:
<xarray.Dataset> Size: 232B
Dimensions:           (costs: 1, techs: 4)
Coordinates:
  * costs             (costs) object 8B 'monetary'
  * techs             (techs) object 32B 'ccgt' 'csp' ... 'region1_to_region2'
Data variables:
    cost_area_use     (costs, techs) float64 32B nan 200.0 nan nan
    cost_flow_cap     (costs, techs) float64 32B 750.0 1e+03 nan 200.0
    cost_flow_in      (costs, techs) float64 32B 0.02 nan nan nan
    cost_flow_out     (costs, techs) float64 32B nan 0.002 nan 0.002
    cost_source_cap   (costs, techs) float64 32B nan 200.0 nan nan
    cost_storage_cap  (costs, techs) float64 32B nan 50.0 200.0 nan.

[2024-12-16 11:49:59] DEBUG    (data_tables, time_varying_parameters) | Updating `timesteps` dimension index values to datetime format.

[2024-12-16 11:50:02] DEBUG    Link distance matrix automatically computed from lat/lon coordinates.

[2024-12-16 11:50:02] INFO     Model: preprocessing stage 2 (model_data)

[2024-12-16 11:50:02] INFO     Model: preprocessing complete

[2024-12-16 11:50:02] INFO     Model: backend build starting

[2024-12-16 11:50:02] DEBUG    Math preprocessing | Loading math: ['plan']

[2024-12-16 11:50:02] INFO     Math preprocessing | added file 'plan'.

[2024-12-16 11:50:02] INFO     Math preprocessing | validated math against schema.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:cap_method | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:cap_method | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:integer_dispatch | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:integer_dispatch | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:force_async_flow | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:force_async_flow | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:flow_cap_per_storage_cap_min | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:flow_cap_per_storage_cap_min | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:flow_cap_min | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:flow_cap_min | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:flow_cap_min_systemwide | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:flow_cap_min_systemwide | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:flow_out_min_relative | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:flow_out_min_relative | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:flow_cap_per_unit | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:flow_cap_per_unit | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:export_max | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:export_max | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:area_use_min | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:area_use_min | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:area_use_per_flow_cap | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:area_use_per_flow_cap | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:storage_cap_min | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:storage_cap_min | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:storage_cap_per_unit | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:storage_cap_per_unit | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:storage_discharge_depth | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:storage_discharge_depth | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:storage_initial | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:storage_initial | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:cyclic_storage | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:cyclic_storage | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:purchased_units_min_systemwide | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:purchased_units_min_systemwide | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:purchased_units_max_systemwide | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:purchased_units_max_systemwide | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:purchased_units_min | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:purchased_units_min | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:purchased_units_max | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:purchased_units_max | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:sink_unit | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:sink_unit | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:sink_use_min | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:sink_use_min | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:sink_use_max | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:sink_use_max | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:source_cap_equals_flow_cap | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:source_cap_equals_flow_cap | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:source_eff | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:source_eff | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:source_use_min | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:source_use_min | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:source_use_equals | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:source_use_equals | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:source_cap_max | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:source_cap_max | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:source_cap_min | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:source_cap_min | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:one_way | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:one_way | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:flow_in_eff_per_distance | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:flow_in_eff_per_distance | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:flow_out_eff_per_distance | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:flow_out_eff_per_distance | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:cost_flow_cap_per_distance | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:cost_flow_cap_per_distance | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:cost_purchase_per_distance | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:cost_purchase_per_distance | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:cost_export | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:cost_export | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:cost_om_annual | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:cost_om_annual | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:cost_om_annual_investment_fraction | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:cost_om_annual_investment_fraction | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:cost_purchase | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:cost_purchase | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:cost_depreciation_rate | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:cost_depreciation_rate | Component not added; no data found in array.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:available_area | Component not defined; using default value.

[2024-12-16 11:50:02] DEBUG    Optimisation model | parameters:available_area | Component not added; no data found in array.

[2024-12-16 11:50:02] INFO     Optimisation Model | parameters | Generated.

[2024-12-16 11:50:05] INFO     Optimisation Model | Validated math strings.

[2024-12-16 11:50:05] DEBUG    Optimisation model | variables:flow_cap | Applying bound according to the flow_cap_max parameter values.

[2024-12-16 11:50:05] DEBUG    Optimisation Model | variables:flow_cap | Built in 0.0161s

[2024-12-16 11:50:05] DEBUG    Optimisation Model | variables:link_flow_cap | Built in 0.0134s

[2024-12-16 11:50:05] DEBUG    Optimisation Model | variables:flow_out | Built in 0.0182s

[2024-12-16 11:50:05] DEBUG    Optimisation Model | variables:flow_in | Built in 0.0193s

[2024-12-16 11:50:05] DEBUG    Math parsing | variables:flow_export | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:05] DEBUG    Optimisation Model | variables:flow_export | Built in 0.0083s

[2024-12-16 11:50:05] DEBUG    Optimisation model | variables:area_use | Applying bound according to the area_use_max parameter values.

[2024-12-16 11:50:05] DEBUG    Optimisation Model | variables:area_use | Built in 0.0225s

[2024-12-16 11:50:05] DEBUG    Optimisation Model | variables:source_use | Built in 0.0164s

[2024-12-16 11:50:05] DEBUG    Optimisation model | variables:source_cap | Applying bound according to the source_cap_max parameter values.

[2024-12-16 11:50:05] DEBUG    Optimisation Model | variables:source_cap | Built in 0.0161s

[2024-12-16 11:50:05] DEBUG    Optimisation model | variables:storage_cap | Applying bound according to the storage_cap_max parameter values.

[2024-12-16 11:50:05] DEBUG    Optimisation Model | variables:storage_cap | Built in 0.0181s

[2024-12-16 11:50:05] DEBUG    Optimisation Model | variables:storage | Built in 0.0186s

[2024-12-16 11:50:05] DEBUG    Math parsing | variables:purchased_units | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:05] DEBUG    Optimisation Model | variables:purchased_units | Built in 0.0079s

[2024-12-16 11:50:05] DEBUG    Math parsing | variables:operating_units | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:05] DEBUG    Optimisation Model | variables:operating_units | Built in 0.0885s

[2024-12-16 11:50:05] DEBUG    Math parsing | variables:available_flow_cap | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:05] DEBUG    Optimisation Model | variables:available_flow_cap | Built in 0.0125s

[2024-12-16 11:50:05] DEBUG    Math parsing | variables:async_flow_switch | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:05] DEBUG    Optimisation Model | variables:async_flow_switch | Built in 0.0085s

[2024-12-16 11:50:05] DEBUG    Optimisation Model | variables:unmet_demand | Built in 0.0169s

[2024-12-16 11:50:05] DEBUG    Optimisation Model | variables:unused_supply | Built in 0.0153s

[2024-12-16 11:50:05] INFO     Optimisation Model | variables | Generated.

[2024-12-16 11:50:05] DEBUG    Optimisation Model | global_expressions:flow_out_inc_eff | Built in 0.0800s

[2024-12-16 11:50:06] DEBUG    Optimisation Model | global_expressions:flow_in_inc_eff | Built in 0.0639s

[2024-12-16 11:50:06] DEBUG    Math parsing | global_expressions:cost_operation_variable:0-cost_flow_out:0-cost_flow_in:0-cost_export:0 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:06] DEBUG    Math parsing | global_expressions:cost_operation_variable:0-cost_flow_out:0-cost_flow_in:1-cost_export:0 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:06] DEBUG    Optimisation Model | global_expressions:cost_operation_variable | Built in 0.1771s

[2024-12-16 11:50:06] DEBUG    Optimisation Model | global_expressions:cost_investment_flow_cap | Built in 0.0853s

[2024-12-16 11:50:06] DEBUG    Optimisation Model | global_expressions:cost_investment_storage_cap | Built in 0.0383s

[2024-12-16 11:50:06] DEBUG    Optimisation Model | global_expressions:cost_investment_source_cap | Built in 0.0378s

[2024-12-16 11:50:06] DEBUG    Optimisation Model | global_expressions:cost_investment_area_use | Built in 0.0374s

[2024-12-16 11:50:06] DEBUG    Math parsing | global_expressions:cost_investment_purchase | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:06] DEBUG    Optimisation Model | global_expressions:cost_investment_purchase | Built in 0.0084s

[2024-12-16 11:50:06] DEBUG    Optimisation Model | global_expressions:cost_investment | Built in 0.0769s

[2024-12-16 11:50:06] DEBUG    Math parsing | global_expressions:cost_investment_annualised:0-depreciation_rate:0-annualisation_weight:0 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:06] DEBUG    Math parsing | global_expressions:cost_investment_annualised:0-depreciation_rate:1-annualisation_weight:0 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:06] DEBUG    Optimisation Model | global_expressions:cost_investment_annualised | Built in 0.2169s

[2024-12-16 11:50:06] DEBUG    Math parsing | global_expressions:cost_operation_fixed | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:06] DEBUG    Optimisation Model | global_expressions:cost_operation_fixed | Built in 0.0111s

[2024-12-16 11:50:06] DEBUG    Optimisation Model | global_expressions:cost | Built in 0.0826s

[2024-12-16 11:50:06] INFO     Optimisation Model | global_expressions | Generated.

[2024-12-16 11:50:06] DEBUG    Math parsing | constraints:flow_capacity_per_storage_capacity_min | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:06] DEBUG    Optimisation Model | constraints:flow_capacity_per_storage_capacity_min | Built in 0.0083s

[2024-12-16 11:50:06] DEBUG    Optimisation Model | constraints:flow_capacity_per_storage_capacity_max | Built in 0.0408s

[2024-12-16 11:50:06] DEBUG    Math parsing | constraints:source_capacity_equals_flow_capacity | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:06] DEBUG    Optimisation Model | constraints:source_capacity_equals_flow_capacity | Built in 0.0088s

[2024-12-16 11:50:06] DEBUG    Math parsing | constraints:force_zero_area_use | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:06] DEBUG    Optimisation Model | constraints:force_zero_area_use | Built in 0.0111s

[2024-12-16 11:50:06] DEBUG    Math parsing | constraints:area_use_per_flow_capacity | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:06] DEBUG    Optimisation Model | constraints:area_use_per_flow_capacity | Built in 0.0082s

[2024-12-16 11:50:06] DEBUG    Math parsing | constraints:area_use_capacity_per_loc | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:06] DEBUG    Optimisation Model | constraints:area_use_capacity_per_loc | Built in 0.0082s

[2024-12-16 11:50:06] DEBUG    Optimisation Model | constraints:flow_capacity_systemwide_max | Built in 0.0394s

[2024-12-16 11:50:06] DEBUG    Math parsing | constraints:flow_capacity_systemwide_min | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:06] DEBUG    Optimisation Model | constraints:flow_capacity_systemwide_min | Built in 0.0068s

[2024-12-16 11:50:06] DEBUG    Math parsing | constraints:balance_conversion | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:06] DEBUG    Optimisation Model | constraints:balance_conversion | Built in 0.0128s

[2024-12-16 11:50:06] DEBUG    Optimisation Model | constraints:flow_out_max | Built in 0.0516s

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:flow_out_min | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Optimisation Model | constraints:flow_out_min | Built in 0.0092s

[2024-12-16 11:50:07] DEBUG    Optimisation Model | constraints:flow_in_max | Built in 0.0477s

[2024-12-16 11:50:07] DEBUG    Optimisation Model | constraints:source_max | Built in 0.0420s

[2024-12-16 11:50:07] DEBUG    Optimisation Model | constraints:storage_max | Built in 0.0394s

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:storage_discharge_depth_limit | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Optimisation Model | constraints:storage_discharge_depth_limit | Built in 0.0102s

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:system_balance:0-flow_export:0-unmet_demand_and_unused_supply:0 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:system_balance:0-flow_export:0-unmet_demand_and_unused_supply:1 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:system_balance:0-flow_export:1-unmet_demand_and_unused_supply:1 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Optimisation Model | constraints:system_balance | Built in 0.1946s

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:balance_demand:0-sink_scaler:0 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:balance_demand:0-sink_scaler:1 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:balance_demand:1-sink_scaler:0 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:balance_demand:1-sink_scaler:1 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:balance_demand:1-sink_scaler:2 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Optimisation Model | constraints:balance_demand | Built in 0.1116s

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:balance_demand_min_use | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Optimisation Model | constraints:balance_demand_min_use | Built in 0.0133s

[2024-12-16 11:50:07] DEBUG    Optimisation Model | constraints:balance_supply_no_storage | Built in 0.0461s

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:balance_supply_with_storage:0-storage_previous_step:0 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:balance_supply_with_storage:0-storage_previous_step:2 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Optimisation Model | constraints:balance_supply_with_storage | Built in 0.2055s

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:source_availability_supply:0-source_scaler:0 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:source_availability_supply:0-source_scaler:1 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:source_availability_supply:0-source_scaler:2 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:source_availability_supply:1-source_scaler:1 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:source_availability_supply:1-source_scaler:2 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Optimisation Model | constraints:source_availability_supply | Built in 0.1134s

[2024-12-16 11:50:07] DEBUG    Math parsing | constraints:balance_supply_min_use | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:07] DEBUG    Optimisation Model | constraints:balance_supply_min_use | Built in 0.0110s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:balance_storage:0-storage_previous_step:0 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:balance_storage:0-storage_previous_step:2 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:balance_storage | Built in 0.2880s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:set_storage_initial | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:set_storage_initial | Built in 0.0102s

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:balance_transmission | Built in 0.0508s

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:symmetric_transmission | Built in 0.0406s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:export_balance | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:export_balance | Built in 0.0086s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:flow_export_max | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:flow_export_max | Built in 0.0089s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:unit_commitment_milp | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:unit_commitment_milp | Built in 0.0094s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:available_flow_cap_binary | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:available_flow_cap_binary | Built in 0.0102s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:available_flow_cap_continuous | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:available_flow_cap_continuous | Built in 0.0083s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:available_flow_cap_max_binary_continuous_switch | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:available_flow_cap_max_binary_continuous_switch | Built in 0.0079s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:flow_out_max_milp | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:flow_out_max_milp | Built in 0.0108s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:flow_in_max_milp | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:flow_in_max_milp | Built in 0.0111s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:flow_out_min_milp | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:flow_out_min_milp | Built in 0.0134s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:storage_capacity_units_milp | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:storage_capacity_units_milp | Built in 0.0097s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:flow_capacity_units_milp | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:flow_capacity_units_milp | Built in 0.0078s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:flow_capacity_max_purchase_milp | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:flow_capacity_max_purchase_milp | Built in 0.0073s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:flow_capacity_minimum | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:flow_capacity_minimum | Built in 0.0086s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:storage_capacity_max_purchase_milp | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:storage_capacity_max_purchase_milp | Built in 0.0090s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:storage_capacity_minimum | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:storage_capacity_minimum | Built in 0.0066s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:area_use_minimum | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:area_use_minimum | Built in 0.0068s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:source_capacity_minimum | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:source_capacity_minimum | Built in 0.0089s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:unit_capacity_max_systemwide_milp | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:unit_capacity_max_systemwide_milp | Built in 0.0097s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:unit_capacity_min_systemwide_milp | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:unit_capacity_min_systemwide_milp | Built in 0.0078s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:async_flow_in_milp | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:async_flow_in_milp | Built in 0.0079s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:async_flow_out_milp | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:async_flow_out_milp | Built in 0.0079s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:ramping_up:0-flow:1 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:ramping_up:0-flow:2 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:ramping_up | Built in 0.1169s

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:ramping_down:0-flow:1 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Math parsing | constraints:ramping_down:0-flow:2 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | constraints:ramping_down | Built in 0.1200s

[2024-12-16 11:50:08] INFO     Optimisation Model | constraints | Generated.

[2024-12-16 11:50:08] INFO     Optimisation Model | piecewise_constraints | Generated.

[2024-12-16 11:50:08] DEBUG    Optimisation model | objectives:min_cost_optimisation | Objective activated.

[2024-12-16 11:50:08] DEBUG    Math parsing | objectives:min_cost_optimisation:0-unmet_demand:1 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Math parsing | objectives:min_cost_optimisation:1-unmet_demand:0 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Math parsing | objectives:min_cost_optimisation:1-unmet_demand:1 | Component not added; 'where' does not apply anywhere.

[2024-12-16 11:50:08] DEBUG    Optimisation Model | objectives:min_cost_optimisation | Built in 0.1838s

[2024-12-16 11:50:08] INFO     Optimisation Model | objectives | Generated.

[2024-12-16 11:50:08] INFO     Model: backend build complete

[2024-12-16 11:50:08] INFO     Optimisation model | starting model in plan mode.

[2024-12-16 11:50:09] DEBUG    Welcome to the CBC MILP Solver 
Version: 2.10.12 
Build Date: Sep  3 2024 

command line - /home/docs/checkouts/readthedocs.org/user_builds/calliope/conda/v0.7.0.dev5/bin/cbc -printingOptions all -import /tmp/tmp2r2lw2ss.pyomo.lp -stat=1 -solve -solu /tmp/tmp2r2lw2ss.pyomo.soln (default strategy 1)
Option for printingOptions changed from normal to all
Presolve 700 (-583) rows, 861 (-177) columns and 2384 (-1088) elements
Statistics for presolved model


Problem has 700 rows, 861 columns (399 with objective) and 2384 elements
There are 240 singletons with objective 
Column breakdown:
732 of type 0.0->inf, 9 of type 0.0->up, 0 of type lo->inf, 
0 of type lo->up, 0 of type free, 0 of type fixed, 
120 of type -inf->0.0, 0 of type -inf->up, 0 of type 0.0->1.0 
Row breakdown:
224 of type E 0.0, 0 of type E 1.0, 0 of type E -1.0, 
48 of type E other, 0 of type G 0.0, 0 of type G 1.0, 
0 of type G other, 428 of type L 0.0, 0 of type L 1.0, 
0 of type L other, 0 of type Range 0.0->1.0, 0 of type Range other, 
0 of type Free 
Presolve 700 (-583) rows, 861 (-177) columns and 2384 (-1088) elements
Perturbing problem by 0.001% of 66.616365 - largest nonzero change 0.00016650948 ( 19.901606%) - largest zero change 0.00016401159
0  Obj 0 Primal inf 708537.92 (48)
89  Obj 64.743123 Primal inf 754880.64 (48)
178  Obj 5172.2946 Primal inf 1817673 (91)
267  Obj 24242.276 Primal inf 1092822.4 (156)
356  Obj 36907.542 Primal inf 167562.17 (121)
445  Obj 39158.214 Primal inf 1.4289021 (15)
460  Obj 39158.345
Optimal - objective value 38988.744
After Postsolve, objective 38988.744, infeasibilities - dual 0 (0), primal 0 (0)
Optimal objective 38988.7442 - 460 iterations time 0.022, Presolve 0.01
Total time (CPU seconds):       0.05   (Wallclock seconds):       0.02

[2024-12-16 11:50:09] INFO     Backend: solver finished running. Time since start of solving optimisation problem: 0:00:00.257552

[2024-12-16 11:50:09] WARNING  Postprocessing: All values < 1e-10 set to 0 in flow_cap

[2024-12-16 11:50:09] INFO     Postprocessing: ended. Time since start of solving optimisation problem: 0:00:00.383135

[2024-12-16 11:50:09] INFO     Backend: model solve completed. Time since start of solving optimisation problem: 0:00:00.385948

Adding your own console logging handler¶

If the calliope.set_log_verbosity method isn't providing you with enough flexibility then you can add your own logging handlers

In [5]:

Copied!





# Grab the calliope logger, which will also automatically get the child loggers (e.g., `calliope.model`).
logger = logging.getLogger("calliope")

# Remove existing handlers (i.e., those introduced by `calliope.set_log_verbosity` above)
logger.handlers.clear()

# You can define your own custom formatter.
# See https://docs.python.org/3/library/logging.html#logrecord-attributes for available attributes.
formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")

# Add a ConsoleHandler (this is what `calliope.set_log_verbosity` is doing under the hood)
console_handler = logging.StreamHandler()
console_handler.setLevel(
    logging.INFO
)  # In this example, we only want to see warnings in the console
console_handler.setFormatter(formatter)
logger.addHandler(console_handler)

# You can also use logging in your scripts to add more information
logger.info("Loading the national-scale example model")
m = calliope.examples.national_scale(time_subset=["2005-01-01", "2005-01-01"])

logger.info("Building the national-scale example model optimisation problem")
m.build()

logger.info("Solving the national-scale example model optimisation problem")
m.solve()
# Grab the calliope logger, which will also automatically get the child loggers (e.g., `calliope.model`).
logger = logging.getLogger("calliope")

# Remove existing handlers (i.e., those introduced by `calliope.set_log_verbosity` above)
logger.handlers.clear()

# You can define your own custom formatter.
# See https://docs.python.org/3/library/logging.html#logrecord-attributes for available attributes.
formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")

# Add a ConsoleHandler (this is what `calliope.set_log_verbosity` is doing under the hood)
console_handler = logging.StreamHandler()
console_handler.setLevel(
    logging.INFO
)  # In this example, we only want to see warnings in the console
console_handler.setFormatter(formatter)
logger.addHandler(console_handler)

# You can also use logging in your scripts to add more information
logger.info("Loading the national-scale example model")
m = calliope.examples.national_scale(time_subset=["2005-01-01", "2005-01-01"])

logger.info("Building the national-scale example model optimisation problem")
m.build()

logger.info("Solving the national-scale example model optimisation problem")
m.solve()

2024-12-16 11:50:09,261 - calliope - INFO - Loading the national-scale example model

2024-12-16 11:50:09,262 - calliope.model - INFO - Model: initialising

2024-12-16 11:50:09,368 - calliope.model - INFO - Model: preprocessing stage 1 (model_run)

2024-12-16 11:50:11,818 - calliope.model - INFO - Model: preprocessing stage 2 (model_data)

2024-12-16 11:50:11,818 - calliope.model - INFO - Model: preprocessing complete

2024-12-16 11:50:11,819 - calliope - INFO - Building the national-scale example model optimisation problem

2024-12-16 11:50:11,820 - calliope.model - INFO - Model: backend build starting

2024-12-16 11:50:11,837 - calliope.preprocess.model_math - INFO - Math preprocessing | added file 'plan'.

2024-12-16 11:50:12,122 - calliope.preprocess.model_math - INFO - Math preprocessing | validated math against schema.

2024-12-16 11:50:12,405 - calliope.backend.backend_model - INFO - Optimisation Model | parameters | Generated.

2024-12-16 11:50:15,120 - calliope.backend.backend_model - INFO - Optimisation Model | Validated math strings.

2024-12-16 11:50:15,417 - calliope.backend.backend_model - INFO - Optimisation Model | variables | Generated.

2024-12-16 11:50:16,312 - calliope.backend.backend_model - INFO - Optimisation Model | global_expressions | Generated.

2024-12-16 11:50:18,176 - calliope.backend.backend_model - INFO - Optimisation Model | constraints | Generated.

2024-12-16 11:50:18,177 - calliope.backend.backend_model - INFO - Optimisation Model | piecewise_constraints | Generated.

2024-12-16 11:50:18,284 - calliope.backend.backend_model - INFO - Optimisation Model | objectives | Generated.

2024-12-16 11:50:18,285 - calliope.model - INFO - Model: backend build complete

2024-12-16 11:50:18,286 - calliope - INFO - Solving the national-scale example model optimisation problem

2024-12-16 11:50:18,287 - calliope.model - INFO - Optimisation model | starting model in plan mode.

2024-12-16 11:50:18,545 - calliope.model - INFO - Backend: solver finished running. Time since start of solving optimisation problem: 0:00:00.257831

2024-12-16 11:50:18,664 - calliope.postprocess.postprocess - WARNING - Postprocessing: All values < 1e-10 set to 0 in flow_cap

2024-12-16 11:50:18,667 - calliope.model - INFO - Postprocessing: ended. Time since start of solving optimisation problem: 0:00:00.379874

2024-12-16 11:50:18,669 - calliope.model - INFO - Backend: model solve completed. Time since start of solving optimisation problem: 0:00:00.382681

Adding your own file logging handler¶

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.

Then, you can search through your logs using your favourite IDE.

In [6]:

Copied!

log_filepath = Path(".") / "outputs" / "5_logging"
log_filepath.mkdir(parents=True, exist_ok=True)
log_filepath = Path(".") / "outputs" / "5_logging"
log_filepath.mkdir(parents=True, exist_ok=True)

In [7]:

Copied!





# Grab the calliope logger, which will also automatically get the child loggers (e.g., `calliope.model`).
logger = logging.getLogger("calliope")

# Remove existing handlers (i.e., those introduced earlier in this notebook)
logger.handlers.clear()

# You can define your own custom formatter.
# See https://docs.python.org/3/library/logging.html#logrecord-attributes for available attributes.
formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")

# Set up a file handler, which will store log outputs in a file
file_handler = logging.FileHandler(log_filepath / "calliope.log")
file_handler.setLevel(logging.DEBUG)
file_handler.setFormatter(formatter)
logger.addHandler(file_handler)

# You can also use logging in your scripts to add more information
logger.info("Loading the national-scale example model")
m = calliope.examples.national_scale(time_subset=["2005-01-01", "2005-01-01"])

logger.info("Building the national-scale example model optimisation problem")
m.build()

logger.info("Solving the national-scale example model optimisation problem")
m.solve()
# Grab the calliope logger, which will also automatically get the child loggers (e.g., `calliope.model`).
logger = logging.getLogger("calliope")

# Remove existing handlers (i.e., those introduced earlier in this notebook)
logger.handlers.clear()

# You can define your own custom formatter.
# See https://docs.python.org/3/library/logging.html#logrecord-attributes for available attributes.
formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")

# Set up a file handler, which will store log outputs in a file
file_handler = logging.FileHandler(log_filepath / "calliope.log")
file_handler.setLevel(logging.DEBUG)
file_handler.setFormatter(formatter)
logger.addHandler(file_handler)

# You can also use logging in your scripts to add more information
logger.info("Loading the national-scale example model")
m = calliope.examples.national_scale(time_subset=["2005-01-01", "2005-01-01"])

logger.info("Building the national-scale example model optimisation problem")
m.build()

logger.info("Solving the national-scale example model optimisation problem")
m.solve()

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.

We can also log both to the console at one level and to file at another:

In [8]:

Copied!





# Grab the calliope logger, which will also automatically get the child loggers (e.g., `calliope.model`).
logger = logging.getLogger("calliope")

# Remove existing handlers (i.e., those introduced earlier in this notebook)
logger.handlers.clear()

# You can define your own custom formatter.
# See https://docs.python.org/3/library/logging.html#logrecord-attributes for available attributes.
formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")

# Add a ConsoleHandler (this is what `calliope.set_log_verbosity` is doing under the hood)
console_handler = logging.StreamHandler()
# Log to console at the INFO level
console_handler.setLevel(logging.INFO)
console_handler.setFormatter(formatter)
logger.addHandler(console_handler)

# Set up a file handler, which will store log outputs in a file
file_handler = logging.FileHandler(log_filepath / "calliope.log")
# Log to file at the DEBUG level
file_handler.setLevel(logging.DEBUG)
file_handler.setFormatter(formatter)
logger.addHandler(file_handler)

# You can also use logging in your scripts to add more information
logger.info("Loading the national-scale example model")
m = calliope.examples.national_scale(time_subset=["2005-01-01", "2005-01-01"])

logger.info("Building the national-scale example model optimisation problem")
m.build()

logger.info("Solving the national-scale example model optimisation problem")
m.solve()
# Grab the calliope logger, which will also automatically get the child loggers (e.g., `calliope.model`).
logger = logging.getLogger("calliope")

# Remove existing handlers (i.e., those introduced earlier in this notebook)
logger.handlers.clear()

# You can define your own custom formatter.
# See https://docs.python.org/3/library/logging.html#logrecord-attributes for available attributes.
formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")

# Add a ConsoleHandler (this is what `calliope.set_log_verbosity` is doing under the hood)
console_handler = logging.StreamHandler()
# Log to console at the INFO level
console_handler.setLevel(logging.INFO)
console_handler.setFormatter(formatter)
logger.addHandler(console_handler)

# Set up a file handler, which will store log outputs in a file
file_handler = logging.FileHandler(log_filepath / "calliope.log")
# Log to file at the DEBUG level
file_handler.setLevel(logging.DEBUG)
file_handler.setFormatter(formatter)
logger.addHandler(file_handler)

# You can also use logging in your scripts to add more information
logger.info("Loading the national-scale example model")
m = calliope.examples.national_scale(time_subset=["2005-01-01", "2005-01-01"])

logger.info("Building the national-scale example model optimisation problem")
m.build()

logger.info("Solving the national-scale example model optimisation problem")
m.solve()

2024-12-16 11:50:28,140 - calliope - INFO - Loading the national-scale example model

2024-12-16 11:50:28,142 - calliope.model - INFO - Model: initialising

2024-12-16 11:50:28,251 - calliope.model - INFO - Model: preprocessing stage 1 (model_run)

2024-12-16 11:50:30,723 - calliope.model - INFO - Model: preprocessing stage 2 (model_data)

2024-12-16 11:50:30,723 - calliope.model - INFO - Model: preprocessing complete

2024-12-16 11:50:30,724 - calliope - INFO - Building the national-scale example model optimisation problem

2024-12-16 11:50:30,725 - calliope.model - INFO - Model: backend build starting

2024-12-16 11:50:30,741 - calliope.preprocess.model_math - INFO - Math preprocessing | added file 'plan'.

2024-12-16 11:50:31,026 - calliope.preprocess.model_math - INFO - Math preprocessing | validated math against schema.

2024-12-16 11:50:31,315 - calliope.backend.backend_model - INFO - Optimisation Model | parameters | Generated.

2024-12-16 11:50:34,107 - calliope.backend.backend_model - INFO - Optimisation Model | Validated math strings.

2024-12-16 11:50:34,419 - calliope.backend.backend_model - INFO - Optimisation Model | variables | Generated.

2024-12-16 11:50:35,347 - calliope.backend.backend_model - INFO - Optimisation Model | global_expressions | Generated.

2024-12-16 11:50:37,223 - calliope.backend.backend_model - INFO - Optimisation Model | constraints | Generated.

2024-12-16 11:50:37,224 - calliope.backend.backend_model - INFO - Optimisation Model | piecewise_constraints | Generated.

2024-12-16 11:50:37,332 - calliope.backend.backend_model - INFO - Optimisation Model | objectives | Generated.

2024-12-16 11:50:37,333 - calliope.model - INFO - Model: backend build complete

2024-12-16 11:50:37,334 - calliope - INFO - Solving the national-scale example model optimisation problem

2024-12-16 11:50:37,335 - calliope.model - INFO - Optimisation model | starting model in plan mode.

2024-12-16 11:50:37,594 - calliope.model - INFO - Backend: solver finished running. Time since start of solving optimisation problem: 0:00:00.258928

2024-12-16 11:50:37,714 - calliope.postprocess.postprocess - WARNING - Postprocessing: All values < 1e-10 set to 0 in flow_cap

2024-12-16 11:50:37,717 - calliope.model - INFO - Postprocessing: ended. Time since start of solving optimisation problem: 0:00:00.381816

2024-12-16 11:50:37,719 - calliope.model - INFO - Backend: model solve completed. Time since start of solving optimisation problem: 0:00:00.384630

The log file will contain all calliope child logger outputs in one place. 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.

We can store each of these child loggers to a different file if we like:

In [9]:

Copied!





# Grab the calliope logger, which will also automatically get the child loggers (e.g., `calliope.model`).
logger = logging.getLogger("calliope")

# Remove existing handlers (i.e., those introduced earlier in this notebook)
logger.handlers.clear()

# You can define your own custom formatter.
# Here we don't include the logger name, as the filename will contain that information.
# See https://docs.python.org/3/library/logging.html#logrecord-attributes for available attributes.
formatter = logging.Formatter("%(asctime)s - %(levelname)s - %(message)s")

for logger_name in logging.root.manager.loggerDict.keys():
    if not logger_name.startswith("calliope"):
        # There are lots of other loggers that calliope imports from its dependencies which we will ignore.
        # You can also dump these log to files if you like, by removing this conditional statement.
        continue
    # Set up a file handler, which will store log outputs in a file
    file_handler = logging.FileHandler(log_filepath / f"{logger_name}.log")
    # Log to file at the DEBUG level
    file_handler.setLevel(logging.DEBUG)
    file_handler.setFormatter(formatter)
    logging.getLogger(logger_name).addHandler(file_handler)

m = calliope.examples.national_scale(time_subset=["2005-01-01", "2005-01-01"])
m.build()
m.solve()
# Grab the calliope logger, which will also automatically get the child loggers (e.g., `calliope.model`).
logger = logging.getLogger("calliope")

# Remove existing handlers (i.e., those introduced earlier in this notebook)
logger.handlers.clear()

# You can define your own custom formatter.
# Here we don't include the logger name, as the filename will contain that information.
# See https://docs.python.org/3/library/logging.html#logrecord-attributes for available attributes.
formatter = logging.Formatter("%(asctime)s - %(levelname)s - %(message)s")

for logger_name in logging.root.manager.loggerDict.keys():
    if not logger_name.startswith("calliope"):
        # There are lots of other loggers that calliope imports from its dependencies which we will ignore.
        # You can also dump these log to files if you like, by removing this conditional statement.
        continue
    # Set up a file handler, which will store log outputs in a file
    file_handler = logging.FileHandler(log_filepath / f"{logger_name}.log")
    # Log to file at the DEBUG level
    file_handler.setLevel(logging.DEBUG)
    file_handler.setFormatter(formatter)
    logging.getLogger(logger_name).addHandler(file_handler)

m = calliope.examples.national_scale(time_subset=["2005-01-01", "2005-01-01"])
m.build()
m.solve()