Merge pull request #83 from childmindresearch/feature/issue-62/add-lo…

…gger

Feature/issue 62/add logger

src/wristpy/core/config.py

@@ -1,5 +1,7 @@
 """Configuration module for wristpy."""
 
+import logging
+
 import pydantic_settings
 
 
@@ -9,3 +11,22 @@ class Settings(pydantic_settings.BaseSettings):
     LIGHT_THRESHOLD: float = 0.03
     MODERATE_THRESHOLD: float = 0.1
     VIGOROUS_THRESHOLD: float = 0.3
+
+    LOGGING_LEVEL: int = logging.INFO
+
+
+def get_logger() -> logging.Logger:
+    """Gets the wristpy logger."""
+    logger = logging.getLogger("wristpy")
+    if logger.handlers:
+        return logger
+
+    logger.setLevel(Settings().LOGGING_LEVEL)
+    formatter = logging.Formatter(
+        "%(asctime)s - %(name)s - %(levelname)s - %(filename)s:%(lineno)s - %(funcName)s - %(message)s",  # noqa: E501
+    )
+
+    handler = logging.StreamHandler()
+    handler.setFormatter(formatter)
+    logger.addHandler(handler)
+    return logger

src/wristpy/processing/analytics.py

@@ -15,6 +15,8 @@
 MODERATE_THRESHOLD = settings.MODERATE_THRESHOLD
 VIGOROUS_THRESHOLD = settings.VIGOROUS_THRESHOLD
 
+logger = config.get_logger()
+
 
 @dataclass
 class SleepWindow:
@@ -83,14 +85,17 @@ def run_sleep_detection(self) -> List[SleepWindow]:
             A list of SleepWindow instances, each instance contains a sleep onset/wakeup
             time pair.
         """
+        logger.debug("Beginning sleep detection.")
         spt_window = self._spt_window(self.anglez)
         sib_periods = self._calculate_sib_periods(self.anglez)
         spt_window_periods = _find_periods(spt_window)
         sib_window_periods = _find_periods(sib_periods)
         sleep_onset_wakeup = self._find_onset_wakeup_times(
             spt_window_periods, sib_window_periods
         )
-
+        logger.debug(
+            "Sleep detection complete. Windows detected: %s", len(sleep_onset_wakeup)
+        )
         return sleep_onset_wakeup
 
     def _spt_window(
@@ -120,6 +125,7 @@ def _spt_window(
               using an accelerometer without sleep diary. Sci Rep 8, 12975 (2018).
               https://doi.org/10.1038/s41598-018-31266-z
         """
+        logger.debug("Finding spt windows, Threshold: %s", threshold)
         long_epoch_median = 300
         long_block = 360
         short_block_gap = 720
@@ -139,7 +145,6 @@ def _spt_window(
         sleep_idx_array_filled = self._fill_false_blocks(
             sleep_candidates, short_block_gap
         )
-
         return models.Measurement(
             measurements=sleep_idx_array_filled, time=anglez_median_long_epoch.time
         )
@@ -166,6 +171,7 @@ def _calculate_sib_periods(
             Duration Using a Wrist-Worn Accelerometer. PLoS One 10, e0142533 (2015).
             https://doi.org/10.1371/journal.pone.0142533
         """
+        logger.debug("Calculating SIB period threshold: %s degrees", threshold_degrees)
         anglez_abs_diff = self._compute_abs_diff_mean_anglez(anglez_data)
 
         anglez_pl_df = pl.DataFrame(
@@ -214,6 +220,11 @@ def _find_onset_wakeup_times(
             If there is no overlap between spt_windows and sib_periods,
             the onset and wakeup lists will be empty.
         """
+        logger.debug(
+            "Finding SIB periods within SPT windows. SPT periods:%s, SIB periods: %s",
+            spt_periods,
+            sib_periods,
+        )
         sleep_windows = []
         for sleep_guide in spt_periods:
             min_onset = None
@@ -229,7 +240,7 @@ def _find_onset_wakeup_times(
                         max_wakeup = inactivity_bout[1]
             if min_onset is not None and max_wakeup is not None:
                 sleep_windows.append(SleepWindow(onset=min_onset, wakeup=max_wakeup))
-
+        logger.debug("Sleep windows found: %s", len(sleep_windows))
         return sleep_windows
 
     def _fill_false_blocks(
@@ -311,6 +322,7 @@ def _find_periods(
         a period. For isolated ones the function returns the same start
         and end time. The list is sorted by time.
     """
+    logger.debug("Finding periods in window measurement.")
     edge_detection = np.convolve([1, 3, 1], window_measurement.measurements, "same")
     single_one = np.nonzero(edge_detection == 3)[0]
 
@@ -328,6 +340,7 @@ def _find_periods(
     all_periods = single_periods + block_periods
     all_periods.sort()
 
+    logger.debug("Found %s periods.", len(all_periods))
     return all_periods
 
 
@@ -349,6 +362,10 @@ def remove_nonwear_from_sleep(
     Returns:
         A List of the filtered sleep windows.
     """
+    logger.debug(
+        "Finding non-wear periods that overlap with any of the %s sleep windows.",
+        len(sleep_windows),
+    )
     nonwear_periods = _find_periods(non_wear_array)
 
     filtered_sleep_windows = []
@@ -369,6 +386,7 @@ def remove_nonwear_from_sleep(
             ):
                 filtered_sleep_windows.append(sleep_window)
 
+    logger.debug("Non-wear removed. %s sleep windows remain.", len(sleep_windows))
     return filtered_sleep_windows
 
 
@@ -400,7 +418,9 @@ def compute_physical_activty_categories(
     Raises:
         ValueError: If the threshold values are not in ascending order.
     """
+    logger.debug("Computing physical activity levels, thresholds: %s", thresholds)
     if list(thresholds) != sorted(thresholds):
+        logger.error("ValueError, thresholds must be in ascending order.")
         raise ValueError("Thresholds must be in ascending order.")
 
     activity_levels = (
@@ -416,5 +436,4 @@ def compute_physical_activty_categories(
         * 2
         + (enmo_epoch1.measurements > thresholds[2]) * 3
     )
-
     return models.Measurement(measurements=activity_levels, time=enmo_epoch1.time)

src/wristpy/processing/calibration.py

@@ -11,28 +11,43 @@
 from sklearn import linear_model
 from sklearn import metrics as sklearn_metrics
 
-from wristpy.core import computations, models
+from wristpy.core import computations, config, models
 
+logger = config.get_logger()
 
-class SphereCriteriaError(Exception):
+
+class LoggedException(Exception):
+    """Base class that automatically logs messages."""
+
+    def __init__(self, message: str) -> None:
+        """Initialize a new instance of the LoggedException class.
+
+        Args:
+            message: The message to display.
+        """
+        logger.exception(message)
+        super().__init__(message)
+
+
+class SphereCriteriaError(LoggedException):
     """Data did not meet the sphere criteria."""
 
     pass
 
 
-class CalibrationError(Exception):
+class CalibrationError(LoggedException):
     """Was not able to lower calibration below error threshold."""
 
     pass
 
 
-class NoMotionError(Exception):
+class NoMotionError(LoggedException):
     """No epochs with zero movement could be found in the data."""
 
     pass
 
 
-class ZeroScaleError(Exception):
+class ZeroScaleError(LoggedException):
     """Scale value went to zero."""
 
     pass
@@ -155,6 +170,7 @@ def run(self, acceleration: models.Measurement) -> models.Measurement:
             CalibrationError: If the calibration process fails to get below the
                 `min_calibration_error` threshold.
         """
+        logger.debug("Starting calibration.")
         data_range = cast(datetime, acceleration.time.max()) - cast(
             datetime, acceleration.time.min()
         )
@@ -201,6 +217,7 @@ def _chunked_calibration(
             CalibrationError: If all possible chunks have been used and the calibration
                 process fails to get below the `min_calibration_error` threshold.
         """
+        logger.debug("Running chunked calibration.")
         for chunk in self._get_chunk(acceleration):
             try:
                 return self._calibrate(chunk)
@@ -222,6 +239,7 @@ def _get_chunk(
             everytime the generator function is called.
 
         """
+        logger.debug("Getting chunk.")
         sampling_rate = Calibration._get_sampling_rate(timestamps=acceleration.time)
         min_samples = int(self.min_calibration_hours * 3600 * sampling_rate)
         chunk_size = int(12 * 3600 * sampling_rate)
@@ -271,6 +289,7 @@ def _calibrate(self, acceleration: models.Measurement) -> LinearTransformation:
             and temperature: an evaluation on four continents. J Appl Physiol (1985)
             2014 Oct 1;117(7):738-44. doi: 10.1152/japplphysiol.00421.2014.
         """
+        logger.debug("Attempting to calibrate...")
         no_motion_data = self._extract_no_motion(acceleration=acceleration)
         linear_transformation = self._closest_point_fit(no_motion_data=no_motion_data)
 
@@ -289,11 +308,15 @@ def _calibrate(self, acceleration: models.Measurement) -> LinearTransformation:
             cal_error_end >= self.min_calibration_error
         ):
             raise CalibrationError(
-                "Calibration error could not be sufficiently minimized."
-                f"Initial Error: {cal_error_initial}, Final Error: {cal_error_end},"
+                "Calibration error could not be sufficiently minimized. "
+                f"Initial Error: {cal_error_initial}, Final Error: {cal_error_end}, "
                 f"Error threshold: {self.min_calibration_error}"
             )
-
+        logger.debug(
+            "Calibration successful. Scale: %s, Offset: %s",
+            linear_transformation.scale,
+            linear_transformation.offset,
+        )
         return linear_transformation
 
     def _extract_no_motion(self, acceleration: models.Measurement) -> np.ndarray:
@@ -324,6 +347,7 @@ def _extract_no_motion(self, acceleration: models.Measurement) -> np.ndarray:
             and temperature: an evaluation on four continents. J Appl Physiol (1985)
             2014 Oct 1;117(7):738-44. doi: 10.1152/japplphysiol.00421.2014.
         """
+        logger.debug("Extracting no motion.")
         moving_sd = computations.moving_std(acceleration, 10)
         moving_mean = computations.moving_mean(acceleration, 10)
         no_motion_check = np.all(
@@ -371,6 +395,7 @@ def _closest_point_fit(self, no_motion_data: np.ndarray) -> LinearTransformation
             and temperature: an evaluation on four continents. J Appl Physiol (1985)
             2014 Oct 1;117(7):738-44. doi: 10.1152/japplphysiol.00421.2014.
         """
+        logger.debug("Beginning closest point fit.")
         sphere_criteria_check = np.all(
             (no_motion_data.min(axis=0) < -self.min_acceleration)
             & (no_motion_data.max(axis=0) > self.min_acceleration)
@@ -410,7 +435,9 @@ def _closest_point_fit(self, no_motion_data: np.ndarray) -> LinearTransformation
                 1 / np.linalg.norm(current - closest_point, axis=1), 100
             )
 
+            logger.debug("Scale: %s, Offset: %s, Residual: %s", scale, offset, residual)
             if abs(residual - previous_residual) < self.error_tolerance:
+                logger.debug("Change in residual below error tolerance, ending loop.}")
                 break
 
             previous_residual = residual

src/wristpy/processing/metrics.py

@@ -3,7 +3,9 @@
 import numpy as np
 import polars as pl
 
-from wristpy.core import models
+from wristpy.core import config, models
+
+logger = config.get_logger()
 
 
 def euclidean_norm_minus_one(acceleration: models.Measurement) -> models.Measurement:
@@ -93,6 +95,7 @@ def detect_nonwear(
     Returns:
         A new Measurment instance with the non-wear flag and corresponding timestamps.
     """
+    logger.debug("Detecting non-wear data.")
     acceleration_grouped_by_short_window = _group_acceleration_data_by_time(
         acceleration, short_epoch_length
     )

tests/unit/test_logger.py

@@ -0,0 +1,29 @@
+"""Test logging in config.py."""
+
+import pytest
+
+from wristpy.core import config
+
+
+def test_get_logger(caplog: pytest.LogCaptureFixture) -> None:
+    """Test the wristpy logger with level set to 20 (info)."""
+    logger = config.get_logger()
+
+    logger.debug("Debug message here.")
+    logger.info("Info message here.")
+    logger.warning("Warning message here.")
+
+    assert logger.getEffectiveLevel() == 20
+    assert "Debug message here" not in caplog.text
+    assert "Info message here." in caplog.text
+    assert "Warning message here." in caplog.text
+
+
+def test_get_logger_second_call() -> None:
+    """Test get logger when a handler already exists."""
+    logger = config.get_logger()
+    second_logger = config.get_logger()
+
+    assert len(logger.handlers) == len(second_logger.handlers) == 1
+    assert logger.handlers[0] is second_logger.handlers[0]
+    assert logger is second_logger