fix(logging): 🐛 Update logging configuration to prevent empty log files and improve experiment log naming

abses/conf/absespy.yaml

@@ -24,6 +24,9 @@ hydra:
         level: WARNING
         formatter: simple
         stream: ext://sys.stderr
+      # Disable Hydra's default file handler
+      # ABSESpy configures root logger to write user module logs to model log files
+      file: null
     root:
       level: INFO
       handlers: [console]

abses/core/experiment.py

@@ -160,24 +160,56 @@ def __init__(
         # Setup experiment-level logger (separate from model run loggers)
         # This ensures experiment-level messages don't mix with model run logs
         # Pass DictConfig directly, don't convert to dict (log_parser needs DictConfig)
+        self._logger: Optional[logging.Logger] = None
         if isinstance(cfg, DictConfig):
             # Create a copy to avoid modifying original
             cfg_dict = OmegaConf.to_container(cfg, resolve=True)
             if isinstance(cfg_dict, dict):
                 cfg_dict["outpath"] = str(self.outpath)  # Convert Path to string
                 cfg_copy = OmegaConf.create(cfg_dict)
-                setup_exp_logger(cfg_copy)
+                self._logger = setup_exp_logger(cfg_copy)
         elif isinstance(cfg, dict):
             # Create a copy to avoid modifying original input
             cfg_copy = cfg.copy()
             cfg_copy["outpath"] = str(self.outpath)  # Convert Path to string
-            setup_exp_logger(cfg_copy)
+            self._logger = setup_exp_logger(cfg_copy)
 
     @property
     def model_cls(self) -> Type[MainModelProtocol]:
         """Model class."""
         return self._manager.model_cls
 
+    @property
+    def name(self) -> str:
+        """Experiment name from configuration.
+
+        Returns:
+            Experiment name from exp.name config, or 'experiment' if not set.
+        """
+        exp_cfg = self._cfg.get("exp", {})
+        if isinstance(exp_cfg, (dict, DictConfig)):
+            return exp_cfg.get("name", "experiment")
+        return "experiment"
+
+    @property
+    def logger(self) -> logging.Logger:
+        """Experiment-level logger for recording experiment logs.
+
+        Use this logger to write messages to the experiment log file
+        (e.g., fire_spread.log) rather than model run logs.
+
+        Example:
+            exp.logger.info("Experiment started")
+            exp.logger.debug("Processing parameters...")
+
+        Returns:
+            The experiment-level logger instance.
+        """
+        if self._logger is None:
+            # Fallback to getting the logger by name
+            self._logger = logging.getLogger(EXP_LOGGER_NAME)
+        return self._logger
+
     @property
     def cfg(self) -> DictConfig:
         """Configuration"""
@@ -448,7 +480,6 @@ def _log_experiment_info(
         logger.info(f"Output directory: {self.outpath}")
         logger.info(f"Logging mode: {logging_mode}")
         logger.info("=" * 60)
-        logger.info("")
 
     def _batch_run_repeats(
         self,

abses/core/model.py

@@ -143,18 +143,17 @@ def __init__(
             reports=collector_cfg, tracker=tracker_backend
         )
 
+        # Setup logging BEFORE initialize() so user logs in initialize() are captured
+        log_cfg = self.settings.get("log", {})
+        if log_cfg:
+            self._setup_logger(log_cfg)
+
         # Call initialize on model first
         self.initialize()
         # Then initialize subsystems
         self.do_each("_initialize", order=DEFAULT_INIT_ORDER)
         self.set_state(State.INIT)
 
-        # Setup logging if configured
-        # Check if new log structure exists
-        log_cfg = self.settings.get("log", {})
-        if log_cfg:
-            self._setup_logger(log_cfg)
-
     @functools.cached_property
     def name(self) -> str:
         """Get the model's name.

abses/utils/analysis.py

@@ -188,6 +188,10 @@ def data(self) -> pd.DataFrame:
         Raises:
             AttributeError: If data has not been loaded yet.
         """
+        if not hasattr(self, "_data"):
+            raise AttributeError(
+                "Data has not been loaded yet. Call read_data() first."
+            )
         return self._data
 
     @data.setter

abses/utils/exp_logging.py

@@ -103,16 +103,18 @@ def setup_exp_logger(
         ) or (isinstance(exp_file_cfg_raw, DictConfig) and "name" in exp_file_cfg_raw)
 
         exp_file_name = exp_file.get("name", "experiment.log")
-        if (
-            logging_mode == "separate"
-            and not name_explicitly_set
-            and exp_file_name == "experiment.log"
-        ):
-            # In separate mode, if name not explicitly set, use run.file.name
-            run_file_cfg = get_file_config(cfg, "run")
-            if run_file_cfg:
-                log_name = str(run_file_cfg.get("name", "model")).replace(".log", "")
-                exp_file_name = f"{log_name}.log"
+        if not name_explicitly_set and exp_file_name == "experiment.log":
+            # If name not explicitly set, use exp.name as experiment log file name
+            if isinstance(cfg, dict):
+                exp_name = cfg.get("exp", {}).get("name")
+            else:
+                try:
+                    exp_name = OmegaConf.select(cfg, "exp.name", default=None)
+                except Exception:
+                    exp_name = None
+
+            if exp_name:
+                exp_file_name = f"{exp_name}.log"
 
         # Get output path
         if isinstance(cfg, dict):
@@ -143,13 +145,17 @@ def setup_exp_logger(
         )
         logger.addHandler(file_handler)
     elif logging_mode == "separate":
-        # In separate mode, if exp.file is not enabled, create experiment log file using run.file.name
-        run_file_cfg = get_file_config(cfg, "run")
-        log_name = (
-            str(run_file_cfg.get("name", "model")).replace(".log", "")
-            if run_file_cfg
-            else "model"
-        )
+        # In separate mode, if exp.file is not enabled, create experiment log file using exp.name
+        # Get exp.name from config
+        if isinstance(cfg, dict):
+            exp_name = cfg.get("exp", {}).get("name")
+        else:
+            try:
+                exp_name = OmegaConf.select(cfg, "exp.name", default=None)
+            except Exception:
+                exp_name = None
+
+        log_name = exp_name if exp_name else "experiment"
 
         # Get output path
         if isinstance(cfg, dict):

abses/utils/logging.py

@@ -121,6 +121,8 @@ def setup_model_logger(
     """Setup logging for a model run.
 
     Configures ABSESpy and Mesa loggers (both 'mesa' and 'MESA') with integrated handlers.
+    Also configures the root logger so that user module logs (e.g., logging.getLogger(__name__))
+    are written to the same model log file.
 
     Args:
         name: Log file name.
@@ -176,6 +178,27 @@ def setup_model_logger(
         mesa_level=mesa_level,
     )
 
+    # Configure root logger to use the same handlers as abses_logger
+    # This ensures user module logs (e.g., logging.getLogger(__name__)) are also captured
+    root_logger = logging.getLogger()
+    root_logger.setLevel(level)
+
+    # Remove existing handlers from root logger to avoid duplicates
+    # But keep Hydra's handlers if any (they handle other logs)
+    for handler in root_logger.handlers[:]:
+        # Only remove handlers that are not Hydra's
+        # Hydra handlers typically have 'hydra' in their name or are configured differently
+        handler_name = getattr(handler, "name", "") or ""
+        if "hydra" not in handler_name.lower():
+            root_logger.removeHandler(handler)
+
+    # Add the same handlers from abses_logger to root logger
+    for handler in abses_logger.handlers:
+        # Create a copy of the handler to avoid sharing state
+        # For FileHandler, we can share the same file
+        if handler not in root_logger.handlers:
+            root_logger.addHandler(handler)
+
     return abses_logger, mesa_logger, mesa_upper_logger
 
 

docs/api/analysis.md

@@ -8,3 +8,4 @@ date: 2024-12-20
 
 :::abses.utils.analysis.ExpAnalyzer
 
+

examples/fire_spread/config.yaml

@@ -40,6 +40,38 @@ time:
   end: 100
 
 log:
-  name: fire_spread
-  level: INFO
-  console: false
+  # Logging mode for repeated runs: once | separate | merge
+  mode: separate
+
+  # Experiment-level logging (progress, summary, etc.)
+  exp:
+    stdout:
+      enabled: true
+      level: INFO
+      format: '[%(asctime)s][%(name)s][%(levelname)s] - %(message)s'
+      datefmt: '%H:%M:%S'
+    file:
+      enabled: true
+      level: INFO
+      format: '[%(asctime)s][%(name)s][%(levelname)s] - %(message)s'
+      datefmt: '%H:%M:%S'
+
+  # Model run-level logging (each model execution)
+  run:
+    stdout:
+      enabled: false
+      level: INFO
+      format: '[%(asctime)s][%(name)s][%(levelname)s] - %(message)s'
+      datefmt: '%H:%M:%S'
+    file:
+      enabled: true
+      level: DEBUG
+      format: '[%(asctime)s][%(name)s][%(levelname)s] - %(message)s'
+      datefmt: '%H:%M:%S'
+      name: model  # Log file name (without extension)
+      rotation: null  # e.g., "1 day", "100 MB"
+      retention: null  # e.g., "10 days"
+    # MESA-specific logging configuration
+    mesa:
+      level: null  # If null, uses run.file.level
+      format: null  # If null, uses run.file.format

examples/fire_spread/model.py

@@ -15,6 +15,7 @@
 - Batch operations with ActorsList
 """
 
+import logging
 from enum import IntEnum
 from typing import Optional
 
@@ -23,6 +24,8 @@
 
 from abses import Experiment, MainModel, PatchCell, raster_attribute
 
+logger = logging.getLogger(__name__)
+
 
 class Tree(PatchCell):
     """
@@ -70,6 +73,7 @@ def ignite(self) -> None:
         """Ignite this tree if intact (tree_state transitions from INTACT to BURNING)."""
         if self._state == self.State.INTACT:
             self._state = self.State.BURNING
+            logger.debug(f"Tree at {self.pos} ignited")
 
     @property
     def state(self) -> int:
@@ -116,6 +120,7 @@ def initialize(self) -> None:
         )
         # Grow trees on selected patches
         chosen_patches.shuffle_do("grow")
+        logger.info(f"Grown {len(chosen_patches)} trees")
 
     def setup(self) -> None:
         """
@@ -174,6 +179,7 @@ def main(cfg: Optional[DictConfig] = None) -> None:
     """
     exp = Experiment(Forest, cfg=cfg)
     exp.batch_run()
+    exp.logger.info(f"Experiment {exp.name} started")
 
 
 if __name__ == "__main__":