From 21720c49147a668897839d3c85c01b9856b638d9 Mon Sep 17 00:00:00 2001 From: Jan Kwakkel Date: Tue, 12 Nov 2024 15:32:03 +0100 Subject: [PATCH 01/12] initial commit --- mesa/mesa_logging.py | 165 +++++++++++++++++++++++++++++++++++++ mesa/model.py | 6 ++ tests/test_mesa_logging.py | 51 ++++++++++++ 3 files changed, 222 insertions(+) create mode 100644 mesa/mesa_logging.py create mode 100644 tests/test_mesa_logging.py diff --git a/mesa/mesa_logging.py b/mesa/mesa_logging.py new file mode 100644 index 00000000000..e0066643b45 --- /dev/null +++ b/mesa/mesa_logging.py @@ -0,0 +1,165 @@ +"""This provides logging functionality for MESA. + +It is modeled on the default `logging approach that comes with Python `_. + + +""" + +import inspect +import logging +from functools import wraps +from logging import DEBUG, INFO + +__all__ = [ + "get_rootlogger", + "get_module_logger", + "log_to_stderr", + "DEBUG", + "INFO", + "DEFAULT_LEVEL", + "LOGGER_NAME", + "method_logger", + "function_logger", +] +LOGGER_NAME = "MESA" +DEFAULT_LEVEL = DEBUG + + +def create_module_logger(name:str|None=None): + """Helper function for creating a module logger. + + Args: + name (str): The name to be given to the logger. If the name is None, the name defaults to the name of the module. + + """ + if name is None: + frm = inspect.stack()[1] + mod = inspect.getmodule(frm[0]) + name = mod.__name__ + logger = logging.getLogger(f"{LOGGER_NAME}.{name}") + + _module_loggers[name] = logger + return logger + + +def get_module_logger(name:str): + """Helper function for getting the module logger. + + Args: + name (str): The name of the module in which the method being decorated is located + + """ + try: + logger = _module_loggers[name] + except KeyError: + logger = create_module_logger(name) + + return logger + + +_rootlogger = None +_module_loggers = {} +_logger = get_module_logger(__name__) + +LOG_FORMAT = "[%(processName)s/%(levelname)s] %(message)s" + + + + +def method_logger(name:str): + """Decorator for adding logging to a method. + + Args: + name (str): The name of the module in which the method being decorated is located + + """ + logger = get_module_logger(name) + classname = inspect.getouterframes(inspect.currentframe())[1][3] + + def real_decorator(func): + @wraps(func) + def wrapper(*args, **kwargs): + # hack, because log is applied to methods, we can get + # object instance as first arguments in args + logger.debug(f"calling {func.__name__} on {classname}") + res = func(*args, **kwargs) + logger.debug(f"completed calling {func.__name__} on {classname}") + return res + + return wrapper + + return real_decorator + +def function_logger(name): + """Decorator for adding logging to a Function. + + Args: + name (str): The name of the module in which the function being decorated is located + + """ + logger = get_module_logger(name) + + def real_decorator(func): + @wraps(func) + def wrapper(*args, **kwargs): + # hack, because log is applied to methods, we can get + # object instance as first arguments in args + logger.debug(f"calling {func.__name__}") + res = func(*args, **kwargs) + logger.debug(f"completed calling {func.__name__}") + return res + + return wrapper + + return real_decorator + + +def get_rootlogger(): + """Returns root logger used by MESA. + + Returns: + the root logger of MESA + + """ + global _rootlogger # noqa: PLW0603 + + if not _rootlogger: + _rootlogger = logging.getLogger(LOGGER_NAME) + _rootlogger.handlers = [] + _rootlogger.addHandler(logging.NullHandler()) + _rootlogger.setLevel(DEBUG) + + return _rootlogger + + +def log_to_stderr(level: int | None = None, pass_root_logger_level: bool = False): + """Turn on logging and add a handler which prints to stderr. + + Args: + level: minimum level of the messages that will be logged + pass_root_logger_level: bool, optional. Default False + if True, all module loggers will be set to the same logging level as the root logger. + + """ + if not level: + level = DEFAULT_LEVEL + + logger = get_rootlogger() + + # avoid creation of multiple stream handlers for logging to console + for entry in logger.handlers: + if (isinstance(entry, logging.StreamHandler)) and (entry.formatter._fmt == LOG_FORMAT): + return logger + + formatter = logging.Formatter(LOG_FORMAT) + handler = logging.StreamHandler() + handler.setLevel(level) + handler.setFormatter(formatter) + logger.addHandler(handler) + logger.propagate = False + + if pass_root_logger_level: + for _, mod_logger in _module_loggers.items(): + mod_logger.setLevel(level) + + return logger diff --git a/mesa/model.py b/mesa/model.py index f89be92e7f6..9a8337ac6f7 100644 --- a/mesa/model.py +++ b/mesa/model.py @@ -18,11 +18,14 @@ import numpy as np from mesa.agent import Agent, AgentSet +from mesa.mesa_logging import create_module_logger, method_logger SeedLike = int | np.integer | Sequence[int] | np.random.SeedSequence RNGLike = np.random.Generator | np.random.BitGenerator +logger = create_module_logger() + class Model: """Base class for models in the Mesa ABM library. @@ -44,6 +47,7 @@ class Model: """ + @method_logger(__name__) def __init__( self, *args: Any, @@ -104,6 +108,7 @@ def __init__( # setup agent registration data structures self._setup_agent_registration() + @method_logger(__name__) def _wrapped_step(self, *args: Any, **kwargs: Any) -> None: """Automatically increments time and steps after calling the user's step method.""" # Automatically increment time and step counters @@ -144,6 +149,7 @@ def _setup_agent_registration(self): [], random=self.random ) # an agenset with all agents + @method_logger(__name__) def register_agent(self, agent): """Register the agent with the model. diff --git a/tests/test_mesa_logging.py b/tests/test_mesa_logging.py new file mode 100644 index 00000000000..ea5c74b49e9 --- /dev/null +++ b/tests/test_mesa_logging.py @@ -0,0 +1,51 @@ +"""Unit tests for mesa_logging.""" +import pytest + +import logging + +import unittest + +from mesa import mesa_logging + + +@pytest.fixture +def tear_down(): + """Pytest fixture to ensure all logging is disabled after testing.""" + yield None + mesa_logging._logger = None + ema_logger = logging.getLogger(mesa_logging.LOGGER_NAME) + ema_logger.handlers = [] + + +def test_get_logger(): + """Test get_logger.""" + mesa_logging._rootlogger = None + logger = mesa_logging.get_rootlogger() + assert logger == logging.getLogger(mesa_logging.LOGGER_NAME) + assert len(logger.handlers) == 1 + assert isinstance(logger.handlers[0], logging.NullHandler) + + logger = mesa_logging.get_rootlogger() + assert logger, logging.getLogger(mesa_logging.LOGGER_NAME) + assert len(logger.handlers) == 1 + assert isinstance(logger.handlers[0], logging.NullHandler) + + +def test_log_to_stderr(): + """Test log_to_stderr.""" + mesa_logging._rootlogger = None + logger = mesa_logging.log_to_stderr(mesa_logging.DEBUG) + assert len(logger.handlers) == 2 + assert logger.level == mesa_logging.DEBUG + + mesa_logging._rootlogger = None + logger = mesa_logging.log_to_stderr() + assert len(logger.handlers) == 2 + assert logger.level == mesa_logging.DEFAULT_LEVEL + + logger = mesa_logging.log_to_stderr() + assert len(logger.handlers) == 2 + assert logger.level == mesa_logging.DEFAULT_LEVEL + + + From 86d5a7d91d451176184ef38805a9e8340490b91c Mon Sep 17 00:00:00 2001 From: Jan Kwakkel Date: Tue, 12 Nov 2024 15:38:07 +0100 Subject: [PATCH 02/12] minor updates --- mesa/examples/basic/boltzmann_wealth_model/app.py | 8 ++++++++ mesa/model.py | 2 +- mesa/visualization/solara_viz.py | 7 +++++++ 3 files changed, 16 insertions(+), 1 deletion(-) diff --git a/mesa/examples/basic/boltzmann_wealth_model/app.py b/mesa/examples/basic/boltzmann_wealth_model/app.py index c03d1763619..8080d0be7fa 100644 --- a/mesa/examples/basic/boltzmann_wealth_model/app.py +++ b/mesa/examples/basic/boltzmann_wealth_model/app.py @@ -1,3 +1,8 @@ +import sys +import os.path + +sys.path.insert(0, os.path.abspath('../../../..')) + from mesa.examples.basic.boltzmann_wealth_model.model import BoltzmannWealth from mesa.visualization import ( SolaraViz, @@ -6,6 +11,9 @@ ) +from mesa.mesa_logging import log_to_stderr, DEBUG +log_to_stderr(DEBUG) + def agent_portrayal(agent): color = agent.wealth # we are using a colormap to translate wealth to color return {"color": color} diff --git a/mesa/model.py b/mesa/model.py index 9a8337ac6f7..6e85fe70498 100644 --- a/mesa/model.py +++ b/mesa/model.py @@ -24,7 +24,7 @@ RNGLike = np.random.Generator | np.random.BitGenerator -logger = create_module_logger() +_mesa_logger = create_module_logger() class Model: """Base class for models in the Mesa ABM library. diff --git a/mesa/visualization/solara_viz.py b/mesa/visualization/solara_viz.py index 10718e8a804..ddc6f749320 100644 --- a/mesa/visualization/solara_viz.py +++ b/mesa/visualization/solara_viz.py @@ -35,12 +35,16 @@ from mesa.experimental.devs.simulator import Simulator from mesa.visualization.user_param import Slider from mesa.visualization.utils import force_update, update_counter +from mesa.mesa_logging import create_module_logger, function_logger + if TYPE_CHECKING: from mesa.model import Model +_mesa_logger = create_module_logger() @solara.component +@function_logger(__name__) def SolaraViz( model: Model | solara.Reactive[Model], components: list[reacton.core.Component] @@ -200,18 +204,21 @@ async def step(): step, dependencies=[playing.value, running.value], prefer_threaded=False ) + @function_logger(__name__) def do_step(): """Advance the model by one step.""" model.value.step() running.value = model.value.running force_update() + @function_logger(__name__) def do_reset(): """Reset the model to its initial state.""" playing.value = False running.value = True model.value = model.value = model.value.__class__(**model_parameters.value) + @function_logger(__name__) def do_play_pause(): """Toggle play/pause.""" playing.value = not playing.value From 6cf996c46f5cb1c9bf08f76944fffb0ab94127b3 Mon Sep 17 00:00:00 2001 From: "pre-commit-ci[bot]" <66853113+pre-commit-ci[bot]@users.noreply.github.com> Date: Thu, 14 Nov 2024 01:26:32 +0000 Subject: [PATCH 03/12] [pre-commit.ci] auto fixes from pre-commit.com hooks for more information, see https://pre-commit.ci --- mesa/examples/basic/boltzmann_wealth_model/app.py | 8 ++++---- mesa/mesa_logging.py | 13 +++++++------ mesa/model.py | 2 +- mesa/visualization/solara_viz.py | 4 ++-- tests/test_mesa_logging.py | 6 +----- 5 files changed, 15 insertions(+), 18 deletions(-) diff --git a/mesa/examples/basic/boltzmann_wealth_model/app.py b/mesa/examples/basic/boltzmann_wealth_model/app.py index 0ad09f391fc..1e38a2d35b1 100644 --- a/mesa/examples/basic/boltzmann_wealth_model/app.py +++ b/mesa/examples/basic/boltzmann_wealth_model/app.py @@ -1,19 +1,19 @@ -import sys import os.path +import sys -sys.path.insert(0, os.path.abspath('../../../..')) +sys.path.insert(0, os.path.abspath("../../../..")) from mesa.examples.basic.boltzmann_wealth_model.model import BoltzmannWealth +from mesa.mesa_logging import DEBUG, log_to_stderr from mesa.visualization import ( SolaraViz, make_plot_component, make_space_component, ) - -from mesa.mesa_logging import log_to_stderr, DEBUG log_to_stderr(DEBUG) + def agent_portrayal(agent): color = agent.wealth # we are using a colormap to translate wealth to color return {"color": color} diff --git a/mesa/mesa_logging.py b/mesa/mesa_logging.py index e0066643b45..c1b32faee16 100644 --- a/mesa/mesa_logging.py +++ b/mesa/mesa_logging.py @@ -25,7 +25,7 @@ DEFAULT_LEVEL = DEBUG -def create_module_logger(name:str|None=None): +def create_module_logger(name: str | None = None): """Helper function for creating a module logger. Args: @@ -42,7 +42,7 @@ def create_module_logger(name:str|None=None): return logger -def get_module_logger(name:str): +def get_module_logger(name: str): """Helper function for getting the module logger. Args: @@ -64,9 +64,7 @@ def get_module_logger(name:str): LOG_FORMAT = "[%(processName)s/%(levelname)s] %(message)s" - - -def method_logger(name:str): +def method_logger(name: str): """Decorator for adding logging to a method. Args: @@ -90,6 +88,7 @@ def wrapper(*args, **kwargs): return real_decorator + def function_logger(name): """Decorator for adding logging to a Function. @@ -148,7 +147,9 @@ def log_to_stderr(level: int | None = None, pass_root_logger_level: bool = False # avoid creation of multiple stream handlers for logging to console for entry in logger.handlers: - if (isinstance(entry, logging.StreamHandler)) and (entry.formatter._fmt == LOG_FORMAT): + if (isinstance(entry, logging.StreamHandler)) and ( + entry.formatter._fmt == LOG_FORMAT + ): return logger formatter = logging.Formatter(LOG_FORMAT) diff --git a/mesa/model.py b/mesa/model.py index adc0a228210..b949cd17eea 100644 --- a/mesa/model.py +++ b/mesa/model.py @@ -25,6 +25,7 @@ _mesa_logger = create_module_logger() + class Model: """Base class for models in the Mesa ABM library. @@ -143,7 +144,6 @@ def agents_by_type(self) -> dict[type[Agent], AgentSet]: """A dictionary where the keys are agent types and the values are the corresponding AgentSets.""" return self._agents_by_type - @method_logger(__name__) def register_agent(self, agent): """Register the agent with the model. diff --git a/mesa/visualization/solara_viz.py b/mesa/visualization/solara_viz.py index 92c72470b90..a7370ee8485 100644 --- a/mesa/visualization/solara_viz.py +++ b/mesa/visualization/solara_viz.py @@ -33,16 +33,16 @@ import mesa.visualization.components.altair_components as components_altair from mesa.experimental.devs.simulator import Simulator +from mesa.mesa_logging import create_module_logger, function_logger from mesa.visualization.user_param import Slider from mesa.visualization.utils import force_update, update_counter -from mesa.mesa_logging import create_module_logger, function_logger - if TYPE_CHECKING: from mesa.model import Model _mesa_logger = create_module_logger() + @solara.component @function_logger(__name__) def SolaraViz( diff --git a/tests/test_mesa_logging.py b/tests/test_mesa_logging.py index ea5c74b49e9..f4609608d3d 100644 --- a/tests/test_mesa_logging.py +++ b/tests/test_mesa_logging.py @@ -1,9 +1,8 @@ """Unit tests for mesa_logging.""" -import pytest import logging -import unittest +import pytest from mesa import mesa_logging @@ -46,6 +45,3 @@ def test_log_to_stderr(): logger = mesa_logging.log_to_stderr() assert len(logger.handlers) == 2 assert logger.level == mesa_logging.DEFAULT_LEVEL - - - From a8b3789c84bd5bb61b6901c476dadd2ff99138dd Mon Sep 17 00:00:00 2001 From: Jan Kwakkel Date: Thu, 14 Nov 2024 03:11:41 +0100 Subject: [PATCH 04/12] minor tweak --- mesa/mesa_logging.py | 10 +++------- mesa/visualization/solara_viz.py | 2 ++ 2 files changed, 5 insertions(+), 7 deletions(-) diff --git a/mesa/mesa_logging.py b/mesa/mesa_logging.py index c1b32faee16..12e7ba86c41 100644 --- a/mesa/mesa_logging.py +++ b/mesa/mesa_logging.py @@ -61,7 +61,7 @@ def get_module_logger(name: str): _module_loggers = {} _logger = get_module_logger(__name__) -LOG_FORMAT = "[%(processName)s/%(levelname)s] %(message)s" +LOG_FORMAT = "[%(name)s %(levelname)s] %(message)s" def method_logger(name: str): @@ -79,9 +79,8 @@ def real_decorator(func): def wrapper(*args, **kwargs): # hack, because log is applied to methods, we can get # object instance as first arguments in args - logger.debug(f"calling {func.__name__} on {classname}") + logger.debug(f"calling {classname}.{func.__name__} with {args[1::]} and {kwargs}") res = func(*args, **kwargs) - logger.debug(f"completed calling {func.__name__} on {classname}") return res return wrapper @@ -101,11 +100,8 @@ def function_logger(name): def real_decorator(func): @wraps(func) def wrapper(*args, **kwargs): - # hack, because log is applied to methods, we can get - # object instance as first arguments in args - logger.debug(f"calling {func.__name__}") + logger.debug(f"calling {func.__name__} with {args} and {kwargs}") res = func(*args, **kwargs) - logger.debug(f"completed calling {func.__name__}") return res return wrapper diff --git a/mesa/visualization/solara_viz.py b/mesa/visualization/solara_viz.py index a7370ee8485..a3b354d61e3 100644 --- a/mesa/visualization/solara_viz.py +++ b/mesa/visualization/solara_viz.py @@ -216,6 +216,7 @@ def do_reset(): """Reset the model to its initial state.""" playing.value = False running.value = True + _mesa_logger.log(10, f"creating new {model.value.__class__} instance with {model_parameters.value}") model.value = model.value = model.value.__class__(**model_parameters.value) @function_logger(__name__) @@ -401,6 +402,7 @@ def ModelCreator( [], ) + @function_logger(__name__) def on_change(name, value): model_parameters.value = {**model_parameters.value, name: value} From a4dbff1a683309bb74d8e1e8aba37abe411b05fc Mon Sep 17 00:00:00 2001 From: "pre-commit-ci[bot]" <66853113+pre-commit-ci[bot]@users.noreply.github.com> Date: Thu, 14 Nov 2024 21:36:51 +0000 Subject: [PATCH 05/12] [pre-commit.ci] auto fixes from pre-commit.com hooks for more information, see https://pre-commit.ci --- mesa/mesa_logging.py | 4 +++- mesa/visualization/solara_viz.py | 5 ++++- 2 files changed, 7 insertions(+), 2 deletions(-) diff --git a/mesa/mesa_logging.py b/mesa/mesa_logging.py index 12e7ba86c41..589fa0afadd 100644 --- a/mesa/mesa_logging.py +++ b/mesa/mesa_logging.py @@ -79,7 +79,9 @@ def real_decorator(func): def wrapper(*args, **kwargs): # hack, because log is applied to methods, we can get # object instance as first arguments in args - logger.debug(f"calling {classname}.{func.__name__} with {args[1::]} and {kwargs}") + logger.debug( + f"calling {classname}.{func.__name__} with {args[1::]} and {kwargs}" + ) res = func(*args, **kwargs) return res diff --git a/mesa/visualization/solara_viz.py b/mesa/visualization/solara_viz.py index a3b354d61e3..294dab34ad4 100644 --- a/mesa/visualization/solara_viz.py +++ b/mesa/visualization/solara_viz.py @@ -216,7 +216,10 @@ def do_reset(): """Reset the model to its initial state.""" playing.value = False running.value = True - _mesa_logger.log(10, f"creating new {model.value.__class__} instance with {model_parameters.value}") + _mesa_logger.log( + 10, + f"creating new {model.value.__class__} instance with {model_parameters.value}", + ) model.value = model.value = model.value.__class__(**model_parameters.value) @function_logger(__name__) From c5d240cd4913cbf11f758c2995e27851b807dad9 Mon Sep 17 00:00:00 2001 From: Jan Kwakkel Date: Sat, 23 Nov 2024 17:12:39 +0100 Subject: [PATCH 06/12] minor tweaks --- mesa/model.py | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/mesa/model.py b/mesa/model.py index b949cd17eea..34a8927fbde 100644 --- a/mesa/model.py +++ b/mesa/model.py @@ -113,11 +113,11 @@ def __init__( [], random=self.random ) # an agenset with all agents - @method_logger(__name__) def _wrapped_step(self, *args: Any, **kwargs: Any) -> None: """Automatically increments time and steps after calling the user's step method.""" # Automatically increment time and step counters self.steps += 1 + _mesa_logger.debug(f"calling model.step for timestep {self.steps} ") # Call the original user-defined step method self._user_step(*args, **kwargs) @@ -144,7 +144,6 @@ def agents_by_type(self) -> dict[type[Agent], AgentSet]: """A dictionary where the keys are agent types and the values are the corresponding AgentSets.""" return self._agents_by_type - @method_logger(__name__) def register_agent(self, agent): """Register the agent with the model. @@ -171,6 +170,7 @@ def register_agent(self, agent): ) self._all_agents.add(agent) + _mesa_logger.debug(f"registered agent with agent_id {agent.agent_id}") def deregister_agent(self, agent): """Deregister the agent with the model. @@ -185,6 +185,7 @@ def deregister_agent(self, agent): del self._agents[agent] self._agents_by_type[type(agent)].remove(agent) self._all_agents.remove(agent) + _mesa_logger.debug(f"deregistered agent with agent_id {agent.agent_id}") def run_model(self) -> None: """Run the model until the end condition is reached. From cff4e7d71042b6baac4b38fc135d5d31d91300f9 Mon Sep 17 00:00:00 2001 From: Jan Kwakkel Date: Sat, 23 Nov 2024 17:15:18 +0100 Subject: [PATCH 07/12] Update model.py --- mesa/model.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/mesa/model.py b/mesa/model.py index 34a8927fbde..738bf9c088c 100644 --- a/mesa/model.py +++ b/mesa/model.py @@ -170,7 +170,7 @@ def register_agent(self, agent): ) self._all_agents.add(agent) - _mesa_logger.debug(f"registered agent with agent_id {agent.agent_id}") + _mesa_logger.debug(f"registered agent with agent_id {agent.unique_id}") def deregister_agent(self, agent): """Deregister the agent with the model. @@ -185,7 +185,7 @@ def deregister_agent(self, agent): del self._agents[agent] self._agents_by_type[type(agent)].remove(agent) self._all_agents.remove(agent) - _mesa_logger.debug(f"deregistered agent with agent_id {agent.agent_id}") + _mesa_logger.debug(f"deregistered agent with agent_id {agent.unique_id}") def run_model(self) -> None: """Run the model until the end condition is reached. From 7d96b190bb4e207bcaa7d1d78beacf581daf60ad Mon Sep 17 00:00:00 2001 From: Jan Kwakkel Date: Sat, 23 Nov 2024 17:32:12 +0100 Subject: [PATCH 08/12] add color to stderrr logging --- mesa/mesa_logging.py | 29 ++++++++++++++++++++++++++--- mesa/model.py | 4 ++-- 2 files changed, 28 insertions(+), 5 deletions(-) diff --git a/mesa/mesa_logging.py b/mesa/mesa_logging.py index 589fa0afadd..95ecc2d1601 100644 --- a/mesa/mesa_logging.py +++ b/mesa/mesa_logging.py @@ -61,8 +61,31 @@ def get_module_logger(name: str): _module_loggers = {} _logger = get_module_logger(__name__) -LOG_FORMAT = "[%(name)s %(levelname)s] %(message)s" +class MESAColorFormatter(logging.Formatter): + """Custom formatter for color based formatting.""" + + grey = "\x1b[38;20m" + green = "\x1b[32m" + yellow = "\x1b[33;20m" + red = "\x1b[31;20m" + bold_red = "\x1b[31;1m" + reset = "\x1b[0m" + format = "[%(asctime)s] [%(name)s] [%(levelname)s] %(message)s [%(filename)s:%(lineno)d]" + + FORMATS = { + logging.DEBUG: grey + format + reset, + logging.INFO: green + format + reset, + logging.WARNING: yellow + format + reset, + logging.ERROR: red + format + reset, + logging.CRITICAL: bold_red + format + reset + } + + def format(self, record): + """Format record.""" + log_fmt = self.FORMATS.get(record.levelno) + formatter = logging.Formatter(log_fmt) + return formatter.format(record) def method_logger(name: str): """Decorator for adding logging to a method. @@ -146,11 +169,11 @@ def log_to_stderr(level: int | None = None, pass_root_logger_level: bool = False # avoid creation of multiple stream handlers for logging to console for entry in logger.handlers: if (isinstance(entry, logging.StreamHandler)) and ( - entry.formatter._fmt == LOG_FORMAT + entry.setFormatter(MESAColorFormatter()) ): return logger - formatter = logging.Formatter(LOG_FORMAT) + formatter = MESAColorFormatter() handler = logging.StreamHandler() handler.setLevel(level) handler.setFormatter(formatter) diff --git a/mesa/model.py b/mesa/model.py index 738bf9c088c..badd74954c1 100644 --- a/mesa/model.py +++ b/mesa/model.py @@ -117,7 +117,7 @@ def _wrapped_step(self, *args: Any, **kwargs: Any) -> None: """Automatically increments time and steps after calling the user's step method.""" # Automatically increment time and step counters self.steps += 1 - _mesa_logger.debug(f"calling model.step for timestep {self.steps} ") + _mesa_logger.info(f"calling model.step for timestep {self.steps} ") # Call the original user-defined step method self._user_step(*args, **kwargs) @@ -170,7 +170,7 @@ def register_agent(self, agent): ) self._all_agents.add(agent) - _mesa_logger.debug(f"registered agent with agent_id {agent.unique_id}") + _mesa_logger.debug(f"registered {agent.__class__.__name__} with agent_id {agent.unique_id}") def deregister_agent(self, agent): """Deregister the agent with the model. From 0d50cf748dcdb3629a26da381f23825157f88e02 Mon Sep 17 00:00:00 2001 From: "pre-commit-ci[bot]" <66853113+pre-commit-ci[bot]@users.noreply.github.com> Date: Sat, 23 Nov 2024 16:32:53 +0000 Subject: [PATCH 09/12] [pre-commit.ci] auto fixes from pre-commit.com hooks for more information, see https://pre-commit.ci --- mesa/mesa_logging.py | 7 +++++-- mesa/model.py | 4 +++- 2 files changed, 8 insertions(+), 3 deletions(-) diff --git a/mesa/mesa_logging.py b/mesa/mesa_logging.py index 95ecc2d1601..9aedb0f06fc 100644 --- a/mesa/mesa_logging.py +++ b/mesa/mesa_logging.py @@ -71,14 +71,16 @@ class MESAColorFormatter(logging.Formatter): red = "\x1b[31;20m" bold_red = "\x1b[31;1m" reset = "\x1b[0m" - format = "[%(asctime)s] [%(name)s] [%(levelname)s] %(message)s [%(filename)s:%(lineno)d]" + format = ( + "[%(asctime)s] [%(name)s] [%(levelname)s] %(message)s [%(filename)s:%(lineno)d]" + ) FORMATS = { logging.DEBUG: grey + format + reset, logging.INFO: green + format + reset, logging.WARNING: yellow + format + reset, logging.ERROR: red + format + reset, - logging.CRITICAL: bold_red + format + reset + logging.CRITICAL: bold_red + format + reset, } def format(self, record): @@ -87,6 +89,7 @@ def format(self, record): formatter = logging.Formatter(log_fmt) return formatter.format(record) + def method_logger(name: str): """Decorator for adding logging to a method. diff --git a/mesa/model.py b/mesa/model.py index badd74954c1..8263926a851 100644 --- a/mesa/model.py +++ b/mesa/model.py @@ -170,7 +170,9 @@ def register_agent(self, agent): ) self._all_agents.add(agent) - _mesa_logger.debug(f"registered {agent.__class__.__name__} with agent_id {agent.unique_id}") + _mesa_logger.debug( + f"registered {agent.__class__.__name__} with agent_id {agent.unique_id}" + ) def deregister_agent(self, agent): """Deregister the agent with the model. From 5e809d19ba1d4c70b225551228ce0d4bbb08f421 Mon Sep 17 00:00:00 2001 From: Jan Kwakkel Date: Sat, 23 Nov 2024 17:48:12 +0100 Subject: [PATCH 10/12] Update mesa_logging.py --- mesa/mesa_logging.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/mesa/mesa_logging.py b/mesa/mesa_logging.py index 9aedb0f06fc..03c114365e3 100644 --- a/mesa/mesa_logging.py +++ b/mesa/mesa_logging.py @@ -172,7 +172,7 @@ def log_to_stderr(level: int | None = None, pass_root_logger_level: bool = False # avoid creation of multiple stream handlers for logging to console for entry in logger.handlers: if (isinstance(entry, logging.StreamHandler)) and ( - entry.setFormatter(MESAColorFormatter()) + isinstance(entry.formatter, MESAColorFormatter) ): return logger From d874dcb96c6ac8584594b8e82411bc2846bbf501 Mon Sep 17 00:00:00 2001 From: Jan Kwakkel Date: Sat, 23 Nov 2024 17:53:41 +0100 Subject: [PATCH 11/12] cleanup --- mesa/examples/basic/boltzmann_wealth_model/app.py | 5 ----- 1 file changed, 5 deletions(-) diff --git a/mesa/examples/basic/boltzmann_wealth_model/app.py b/mesa/examples/basic/boltzmann_wealth_model/app.py index 1e38a2d35b1..bc596ce95ae 100644 --- a/mesa/examples/basic/boltzmann_wealth_model/app.py +++ b/mesa/examples/basic/boltzmann_wealth_model/app.py @@ -1,8 +1,3 @@ -import os.path -import sys - -sys.path.insert(0, os.path.abspath("../../../..")) - from mesa.examples.basic.boltzmann_wealth_model.model import BoltzmannWealth from mesa.mesa_logging import DEBUG, log_to_stderr from mesa.visualization import ( From b5251d1a83760817c21390af0db3ea60de69f973 Mon Sep 17 00:00:00 2001 From: Jan Kwakkel Date: Sat, 23 Nov 2024 17:56:23 +0100 Subject: [PATCH 12/12] add to docs --- docs/apis/api_main.md | 1 + docs/apis/mesa_logging.md | 7 +++++++ 2 files changed, 8 insertions(+) create mode 100644 docs/apis/mesa_logging.md diff --git a/docs/apis/api_main.md b/docs/apis/api_main.md index 61b29f13390..6a3ef810f52 100644 --- a/docs/apis/api_main.md +++ b/docs/apis/api_main.md @@ -10,5 +10,6 @@ space datacollection batchrunner visualization +logging experimental ``` diff --git a/docs/apis/mesa_logging.md b/docs/apis/mesa_logging.md new file mode 100644 index 00000000000..d934e0c7488 --- /dev/null +++ b/docs/apis/mesa_logging.md @@ -0,0 +1,7 @@ +# logging + +```{eval-rst} +.. automodule:: mesa.mesa_logging + :members: + :inherited-members: +```