How to use logging

optimagic can keep a persistent log of the parameter and criterion values tried out by an optimizer in a sqlite database.

Turn logging on or off

To enable logging, it suffices to provide a path to an sqlite database when calling maximize or minimize. The database does not have to exist, optimagic will generate it for you.

from pathlib import Path

import numpy as np
import plotly.io as pio

pio.renderers.default = "notebook_connected"

import optimagic as om
def sphere(params):
    return params @ params
# Remove the log file if it exists (just needed for the example)
log_file = Path("my_log.db")
if log_file.exists():
    log_file.unlink()

res = om.minimize(
    fun=sphere,
    params=np.arange(5),
    algorithm="scipy_lbfgsb",
    logging="my_log.db",
)

In case the SQLite file already exists, this will raise a FileExistsError to prevent from accidentally polluting an existing database. If you want to reuse an existing database on purpose, you must explicitly provide the corresponding option for if_database_exists:

log_options = om.SQLiteLogOptions(
    "my_log.db", if_database_exists=om.ExistenceStrategy.EXTEND
)

res = om.minimize(
    fun=sphere,
    params=np.arange(5),
    algorithm="scipy_lbfgsb",
    logging=log_options,
)

Make logging faster

By default, we use a very safe mode of sqlite that makes it almost impossible to corrupt the database. Even if your computer is suddenly shut down or unplugged.

However, this makes writing logs rather slow, which becomes notable when the criterion function is very fast.

In that case, you can enable fast_logging, which is still quite safe!

log_options = om.SQLiteLogOptions(
    "my_log.db",
    fast_logging=True,
    if_database_exists=om.ExistenceStrategy.REPLACE,
)

res = om.minimize(
    fun=sphere,
    params=np.arange(5),
    algorithm="scipy_lbfgsb",
    logging=log_options,
)
---------------------------------------------------------------------------
OperationalError                          Traceback (most recent call last)
File ~/checkouts/readthedocs.org/user_builds/estimagic/conda/v0.5.3/lib/python3.12/site-packages/sqlalchemy/engine/base.py:1967, in Connection._exec_single_context(self, dialect, context, statement, parameters)
   1966     if not evt_handled:
-> 1967         self.dialect.do_execute(
   1968             cursor, str_statement, effective_parameters, context
   1969         )
   1971 if self._has_events or self.engine._has_events:

File ~/checkouts/readthedocs.org/user_builds/estimagic/conda/v0.5.3/lib/python3.12/site-packages/sqlalchemy/engine/default.py:952, in DefaultDialect.do_execute(self, cursor, statement, parameters, context)
    951 def do_execute(self, cursor, statement, parameters, context=None):
--> 952     cursor.execute(statement, parameters)

OperationalError: disk I/O error

The above exception was the direct cause of the following exception:

OperationalError                          Traceback (most recent call last)
Cell In[5], line 7
      1 log_options = om.SQLiteLogOptions(
      2     "my_log.db",
      3     fast_logging=True,
      4     if_database_exists=om.ExistenceStrategy.REPLACE,
      5 )
----> 7 res = om.minimize(
      8     fun=sphere,
      9     params=np.arange(5),
     10     algorithm="scipy_lbfgsb",
     11     logging=log_options,
     12 )

File ~/checkouts/readthedocs.org/user_builds/estimagic/checkouts/v0.5.3/src/optimagic/optimization/optimize.py:481, in minimize(fun, params, algorithm, bounds, constraints, fun_kwargs, algo_options, jac, jac_kwargs, fun_and_jac, fun_and_jac_kwargs, numdiff_options, logging, error_handling, error_penalty, scaling, multistart, collect_history, skip_checks, x0, method, args, hess, hessp, callback, options, tol, criterion, criterion_kwargs, derivative, derivative_kwargs, criterion_and_derivative, criterion_and_derivative_kwargs, log_options, lower_bounds, upper_bounds, soft_lower_bounds, soft_upper_bounds, scaling_options, multistart_options)
    334 """Minimize criterion using algorithm subject to constraints.
    335 
    336 Args:
   (...)    431 
    432 """
    434 problem = create_optimization_problem(
    435     direction=Direction.MINIMIZE,
    436     fun=fun,
   (...)    479     multistart_options=multistart_options,
    480 )
--> 481 return _optimize(problem)

File ~/checkouts/readthedocs.org/user_builds/estimagic/checkouts/v0.5.3/src/optimagic/optimization/optimize.py:554, in _optimize(problem)
    551 logger: LogStore[Any, Any] | None
    553 if problem.logging:
--> 554     logger = LogStore.from_options(problem.logging)
    555     problem_data = ProblemInitialization(problem.direction, problem.params)
    556     logger.problem_store.insert(problem_data)

File ~/checkouts/readthedocs.org/user_builds/estimagic/checkouts/v0.5.3/src/optimagic/logging/logger.py:347, in LogStore.from_options(cls, log_options)
    340 if logger_class is None:
    341     raise ValueError(
    342         f"No Logger implementation found for type "
    343         f"{type(log_options)}. Available option types: "
    344         f"\n {list(_LOG_OPTION_LOGGER_REGISTRY.keys())}"
    345     )
--> 347 return logger_class.create(log_options)

File ~/checkouts/readthedocs.org/user_builds/estimagic/checkouts/v0.5.3/src/optimagic/logging/logger.py:517, in _SQLiteLogStore.create(cls, log_options)
    513 @classmethod
    514 def create(cls, log_options: SQLiteLogOptions) -> _SQLiteLogStore:
    515     cls._handle_existing_database(log_options.path, log_options.if_database_exists)
--> 517     iteration_store = IterationStore(log_options)
    518     step_store = StepStore(log_options)
    519     problem_store = ProblemStore(log_options)

File ~/checkouts/readthedocs.org/user_builds/estimagic/checkouts/v0.5.3/src/optimagic/logging/sqlalchemy.py:395, in IterationStore.__init__(self, db_config)
    391 def __init__(
    392     self,
    393     db_config: SQLAlchemyConfig,
    394 ):
--> 395     super().__init__(
    396         self._TABLE_NAME,
    397         self._PRIMARY_KEY,
    398         db_config,
    399         IterationState,
    400         IterationStateWithId,
    401     )

File ~/checkouts/readthedocs.org/user_builds/estimagic/checkouts/v0.5.3/src/optimagic/logging/sqlalchemy.py:237, in SQLAlchemySimpleStore.__init__(self, table_name, primary_key, db_config, input_type, output_type)
    231 columns = [
    232     sql.Column(primary_key, sql.Integer, primary_key=True, autoincrement=True),
    233     sql.Column(self._value_column, sql.PickleType(pickler=RobustPickler)),  # type:ignore
    234 ]
    235 table_config = TableConfig(table_name, columns, self.primary_key)
--> 237 _SQLAlchemyStoreMixin.__init__(self, db_config, table_config)

File ~/checkouts/readthedocs.org/user_builds/estimagic/checkouts/v0.5.3/src/optimagic/logging/sqlalchemy.py:145, in _SQLAlchemyStoreMixin.__init__(self, db_config, table_config)
    143 self._engine = db_config.create_engine()
    144 self._table_config = table_config
--> 145 self._table = table_config.create_table(db_config.metadata, self._engine)

File ~/checkouts/readthedocs.org/user_builds/estimagic/conda/v0.5.3/lib/python3.12/functools.py:998, in cached_property.__get__(self, instance, owner)
    996 val = cache.get(self.attrname, _NOT_FOUND)
    997 if val is _NOT_FOUND:
--> 998     val = self.func(instance)
    999     try:
   1000         cache[self.attrname] = val

File ~/checkouts/readthedocs.org/user_builds/estimagic/checkouts/v0.5.3/src/optimagic/logging/sqlalchemy.py:60, in SQLAlchemyConfig.metadata(self)
     58 metadata = MetaData()
     59 self._configure_reflect()
---> 60 metadata.reflect(engine)
     61 return metadata

File ~/checkouts/readthedocs.org/user_builds/estimagic/conda/v0.5.3/lib/python3.12/site-packages/sqlalchemy/sql/schema.py:5836, in MetaData.reflect(self, bind, schema, views, only, extend_existing, autoload_replace, resolve_fks, **dialect_kwargs)
   5832     reflect_opts["schema"] = schema
   5834 kind = util.preloaded.engine_reflection.ObjectKind.TABLE
   5835 available: util.OrderedSet[str] = util.OrderedSet(
-> 5836     insp.get_table_names(schema, **dialect_kwargs)
   5837 )
   5838 if views:
   5839     kind = util.preloaded.engine_reflection.ObjectKind.ANY

File ~/checkouts/readthedocs.org/user_builds/estimagic/conda/v0.5.3/lib/python3.12/site-packages/sqlalchemy/engine/reflection.py:406, in Inspector.get_table_names(self, schema, **kw)
    380 r"""Return all table names within a particular schema.
    381 
    382 The names are expected to be real tables only, not views.
   (...)    402 
    403 """
    405 with self._operation_context() as conn:
--> 406     return self.dialect.get_table_names(
    407         conn, schema, info_cache=self.info_cache, **kw
    408     )

File <string>:2, in get_table_names(self, connection, schema, sqlite_include_internal, **kw)

File ~/checkouts/readthedocs.org/user_builds/estimagic/conda/v0.5.3/lib/python3.12/site-packages/sqlalchemy/engine/reflection.py:106, in cache(fn, self, con, *args, **kw)
    104 ret: _R = info_cache.get(key)
    105 if ret is None:
--> 106     ret = fn(self, con, *args, **kw)
    107     info_cache[key] = ret
    108 return ret

File ~/checkouts/readthedocs.org/user_builds/estimagic/conda/v0.5.3/lib/python3.12/site-packages/sqlalchemy/dialects/sqlite/base.py:2292, in SQLiteDialect.get_table_names(self, connection, schema, sqlite_include_internal, **kw)
   2285 @reflection.cache
   2286 def get_table_names(
   2287     self, connection, schema=None, sqlite_include_internal=False, **kw
   2288 ):
   2289     query = self._sqlite_main_query(
   2290         "sqlite_master", "table", schema, sqlite_include_internal
   2291     )
-> 2292     names = connection.exec_driver_sql(query).scalars().all()
   2293     return names

File ~/checkouts/readthedocs.org/user_builds/estimagic/conda/v0.5.3/lib/python3.12/site-packages/sqlalchemy/engine/base.py:1779, in Connection.exec_driver_sql(self, statement, parameters, execution_options)
   1774 execution_options = self._execution_options.merge_with(
   1775     execution_options
   1776 )
   1778 dialect = self.dialect
-> 1779 ret = self._execute_context(
   1780     dialect,
   1781     dialect.execution_ctx_cls._init_statement,
   1782     statement,
   1783     None,
   1784     execution_options,
   1785     statement,
   1786     distilled_parameters,
   1787 )
   1789 return ret

File ~/checkouts/readthedocs.org/user_builds/estimagic/conda/v0.5.3/lib/python3.12/site-packages/sqlalchemy/engine/base.py:1846, in Connection._execute_context(self, dialect, constructor, statement, parameters, execution_options, *args, **kw)
   1844     return self._exec_insertmany_context(dialect, context)
   1845 else:
-> 1846     return self._exec_single_context(
   1847         dialect, context, statement, parameters
   1848     )

File ~/checkouts/readthedocs.org/user_builds/estimagic/conda/v0.5.3/lib/python3.12/site-packages/sqlalchemy/engine/base.py:1986, in Connection._exec_single_context(self, dialect, context, statement, parameters)
   1983     result = context._setup_result_proxy()
   1985 except BaseException as e:
-> 1986     self._handle_dbapi_exception(
   1987         e, str_statement, effective_parameters, cursor, context
   1988     )
   1990 return result

File ~/checkouts/readthedocs.org/user_builds/estimagic/conda/v0.5.3/lib/python3.12/site-packages/sqlalchemy/engine/base.py:2363, in Connection._handle_dbapi_exception(self, e, statement, parameters, cursor, context, is_sub_exec)
   2361 elif should_wrap:
   2362     assert sqlalchemy_exception is not None
-> 2363     raise sqlalchemy_exception.with_traceback(exc_info[2]) from e
   2364 else:
   2365     assert exc_info[1] is not None

File ~/checkouts/readthedocs.org/user_builds/estimagic/conda/v0.5.3/lib/python3.12/site-packages/sqlalchemy/engine/base.py:1967, in Connection._exec_single_context(self, dialect, context, statement, parameters)
   1965                 break
   1966     if not evt_handled:
-> 1967         self.dialect.do_execute(
   1968             cursor, str_statement, effective_parameters, context
   1969         )
   1971 if self._has_events or self.engine._has_events:
   1972     self.dispatch.after_cursor_execute(
   1973         self,
   1974         cursor,
   (...)   1978         context.executemany,
   1979     )

File ~/checkouts/readthedocs.org/user_builds/estimagic/conda/v0.5.3/lib/python3.12/site-packages/sqlalchemy/engine/default.py:952, in DefaultDialect.do_execute(self, cursor, statement, parameters, context)
    951 def do_execute(self, cursor, statement, parameters, context=None):
--> 952     cursor.execute(statement, parameters)

OperationalError: (sqlite3.OperationalError) disk I/O error
[SQL: SELECT name FROM sqlite_master WHERE type='table' AND name NOT LIKE 'sqlite~_%' ESCAPE '~' ORDER BY name]
(Background on this error at: https://sqlalche.me/e/20/e3q8)

Reading the log

To read the log after an optimization, extract the logger from the optimization result:

reader = res.logger

Alternatively, you can create the reader like this:

reader = om.SQLiteLogReader("my_log.db")

Read the start params

reader.read_start_params()

Read a specific iteration (use -1 for the last)

reader.read_iteration(-1)

Read the full history

reader.read_history().keys()

Plot the history from a log

fig = om.criterion_plot("my_log.db")
fig.show()
fig = om.params_plot("my_log.db", selector=lambda x: x[1:3])
fig.show()