diff --git a/custom_components/tibber_prices/coordinator/period_handlers/core.py b/custom_components/tibber_prices/coordinator/period_handlers/core.py index d830095..c61a2f6 100644 --- a/custom_components/tibber_prices/coordinator/period_handlers/core.py +++ b/custom_components/tibber_prices/coordinator/period_handlers/core.py @@ -127,9 +127,13 @@ def calculate_periods( # High flex (>25%) makes outlier detection too permissive, accepting # unstable price contexts as "normal". This breaks period formation. # User's flex setting still applies to period criteria (in_flex check). + + # Import details logger locally (core.py imports logger locally in function) + _LOGGER_DETAILS = logging.getLogger(__name__ + ".details") # noqa: N806 + outlier_flex = min(abs(flex) * 100, MAX_OUTLIER_FLEX * 100) if abs(flex) * 100 > MAX_OUTLIER_FLEX * 100: - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%sOutlier filtering: Using capped flex %.1f%% (user setting: %.1f%%)", INDENT_L0, outlier_flex, diff --git a/custom_components/tibber_prices/coordinator/period_handlers/outlier_filtering.py b/custom_components/tibber_prices/coordinator/period_handlers/outlier_filtering.py index 18a2649..e176c07 100644 --- a/custom_components/tibber_prices/coordinator/period_handlers/outlier_filtering.py +++ b/custom_components/tibber_prices/coordinator/period_handlers/outlier_filtering.py @@ -18,6 +18,7 @@ import logging from typing import NamedTuple _LOGGER = logging.getLogger(__name__) +_LOGGER_DETAILS = logging.getLogger(__name__ + ".details") # Outlier filtering constants MIN_CONTEXT_SIZE = 3 # Minimum intervals needed before/after for analysis @@ -52,7 +53,7 @@ def _should_skip_tail_check( ) -> bool: """Return True when remaining intervals fall inside tail window and log why.""" if remaining_intervals < tail_window: - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%sSpike at %s: Skipping %s check (only %d intervals remaining)", INDENT_L0, interval_label, @@ -190,7 +191,7 @@ def _validate_spike_candidate( context_diff_pct = abs(avg_after - avg_before) / avg_before if avg_before > 0 else 0 if context_diff_pct > candidate.flexibility_ratio: - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%sInterval %s: Context unstable (%.1f%% change) - not a spike", INDENT_L0, candidate.current.get("startsAt", "unknown interval"), @@ -204,7 +205,7 @@ def _validate_spike_candidate( "asymmetry", candidate.current.get("startsAt", "unknown interval"), ) and not _check_symmetry(avg_before, avg_after, candidate.stats["std_dev"]): - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%sSpike at %s rejected: Asymmetric (before=%.2f, after=%.2f ct/kWh)", INDENT_L0, candidate.current.get("startsAt", "unknown interval"), @@ -222,7 +223,7 @@ def _validate_spike_candidate( return True if _detect_zigzag_pattern(candidate.analysis_window, candidate.stats["std_dev"]): - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%sSpike at %s rejected: Zigzag/cluster pattern detected", INDENT_L0, candidate.current.get("startsAt", "unknown interval"), @@ -330,7 +331,7 @@ def filter_price_outliers( result.append(smoothed) smoothed_count += 1 - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%sSmoothed spike at %s: %.2f → %.2f ct/kWh (residual: %.2f, tolerance: %.2f, trend_slope: %.4f)", INDENT_L0, current.get("startsAt", f"index {i}"), diff --git a/custom_components/tibber_prices/coordinator/period_handlers/period_building.py b/custom_components/tibber_prices/coordinator/period_handlers/period_building.py index 5e251d2..e69af8f 100644 --- a/custom_components/tibber_prices/coordinator/period_handlers/period_building.py +++ b/custom_components/tibber_prices/coordinator/period_handlers/period_building.py @@ -19,6 +19,7 @@ from .level_filtering import ( from .types import TibberPricesIntervalCriteria _LOGGER = logging.getLogger(__name__) +_LOGGER_DETAILS = logging.getLogger(__name__ + ".details") # Module-local log indentation (each module starts at level 0) INDENT_L0 = "" # Entry point / main function @@ -92,7 +93,7 @@ def build_periods( # noqa: PLR0913, PLR0915, PLR0912 - Complex period building level_filter_active = True filter_direction = "≥" if reverse_sort else "≤" gap_info = f", gap_tolerance={gap_count}" if gap_count > 0 else "" - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%sLevel filter active: %s (order %s, require interval level %s filter level%s)", INDENT_L0, level_filter.upper(), @@ -102,7 +103,7 @@ def build_periods( # noqa: PLR0913, PLR0915, PLR0912 - Complex period building ) else: status = "RELAXED to ANY" if (level_filter and level_filter.lower() == "any") else "DISABLED (not configured)" - _LOGGER.debug("%sLevel filter: %s (accepting all levels)", INDENT_L0, status) + _LOGGER_DETAILS.debug("%sLevel filter: %s (accepting all levels)", INDENT_L0, status) periods: list[list[dict]] = [] current_period: list[dict] = [] @@ -191,14 +192,14 @@ def build_periods( # noqa: PLR0913, PLR0915, PLR0912 - Complex period building # Log detailed filter statistics if intervals_checked > 0: - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%sFilter statistics: %d intervals checked", INDENT_L0, intervals_checked, ) if intervals_filtered_by_flex > 0: flex_pct = (intervals_filtered_by_flex / intervals_checked) * 100 - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%s Filtered by FLEX (price too far from ref): %d/%d (%.1f%%)", INDENT_L0, intervals_filtered_by_flex, @@ -207,7 +208,7 @@ def build_periods( # noqa: PLR0913, PLR0915, PLR0912 - Complex period building ) if intervals_filtered_by_min_distance > 0: distance_pct = (intervals_filtered_by_min_distance / intervals_checked) * 100 - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%s Filtered by MIN_DISTANCE (price too close to avg): %d/%d (%.1f%%)", INDENT_L0, intervals_filtered_by_min_distance, @@ -216,7 +217,7 @@ def build_periods( # noqa: PLR0913, PLR0915, PLR0912 - Complex period building ) if level_filter_active and intervals_filtered_by_level > 0: level_pct = (intervals_filtered_by_level / intervals_checked) * 100 - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%s Filtered by LEVEL (wrong price level): %d/%d (%.1f%%)", INDENT_L0, intervals_filtered_by_level, diff --git a/custom_components/tibber_prices/coordinator/period_handlers/period_overlap.py b/custom_components/tibber_prices/coordinator/period_handlers/period_overlap.py index dd45f40..7457c3b 100644 --- a/custom_components/tibber_prices/coordinator/period_handlers/period_overlap.py +++ b/custom_components/tibber_prices/coordinator/period_handlers/period_overlap.py @@ -9,6 +9,7 @@ if TYPE_CHECKING: from custom_components.tibber_prices.coordinator.time_service import TibberPricesTimeService _LOGGER = logging.getLogger(__name__) +_LOGGER_DETAILS = logging.getLogger(__name__ + ".details") # Module-local log indentation (each module starts at level 0) INDENT_L0 = "" # Entry point / main function diff --git a/custom_components/tibber_prices/coordinator/period_handlers/relaxation.py b/custom_components/tibber_prices/coordinator/period_handlers/relaxation.py index ec13a4f..353aa44 100644 --- a/custom_components/tibber_prices/coordinator/period_handlers/relaxation.py +++ b/custom_components/tibber_prices/coordinator/period_handlers/relaxation.py @@ -24,6 +24,7 @@ from .types import ( ) _LOGGER = logging.getLogger(__name__) +_LOGGER_DETAILS = logging.getLogger(__name__ + ".details") # Flex thresholds for warnings (see docs/development/period-calculation-theory.md) # With relaxation active, high base flex is counterproductive (reduces relaxation effectiveness) @@ -204,38 +205,38 @@ def calculate_periods_with_relaxation( # noqa: PLR0913, PLR0915 - Per-day relax # Detailed DEBUG-level context header period_type_full = "PEAK PRICE (most expensive)" if config.reverse_sort else "BEST PRICE (cheapest)" - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%s========== %s PERIODS ==========", INDENT_L0, period_type_full, ) - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%sRelaxation: %s", INDENT_L0, "ENABLED (user setting: ON)" if enable_relaxation else "DISABLED by user configuration", ) - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%sBase config: flex=%.1f%%, min_length=%d min", INDENT_L0, abs(config.flex) * 100, config.min_period_length, ) if enable_relaxation: - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%sRelaxation target: %d periods per day", INDENT_L0, min_periods, ) - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%sRelaxation strategy: 3%% fixed flex increment per step (%d flex levels x 2 filter combinations)", INDENT_L0, max_relaxation_attempts, ) - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%sEarly exit: After EACH filter combination when target reached", INDENT_L0, ) - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%s=============================================", INDENT_L0, ) @@ -266,7 +267,7 @@ def calculate_periods_with_relaxation( # noqa: PLR0913, PLR0915 - Per-day relax "Calculating baseline periods for %d days...", total_days, ) - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%sProcessing ALL %d price intervals together (yesterday+today+tomorrow, allows midnight crossing)", INDENT_L1, len(all_prices), @@ -285,7 +286,7 @@ def calculate_periods_with_relaxation( # noqa: PLR0913, PLR0915 - Per-day relax day_periods = periods_by_day.get(day, []) period_count = len(day_periods) - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%sDay %s baseline: Found %d periods%s", INDENT_L1, day, @@ -302,7 +303,7 @@ def calculate_periods_with_relaxation( # noqa: PLR0913, PLR0915 - Per-day relax if enable_relaxation and days_meeting_requirement < total_days: # At least one day doesn't have enough periods - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%sBaseline insufficient (%d/%d days met target) - starting relaxation", INDENT_L1, days_meeting_requirement, @@ -334,7 +335,7 @@ def calculate_periods_with_relaxation( # noqa: PLR0913, PLR0915 - Per-day relax if period_count >= min_periods: days_meeting_requirement += 1 elif enable_relaxation: - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%sAll %d days met target with baseline - no relaxation needed", INDENT_L1, total_days, @@ -422,7 +423,7 @@ def relax_all_prices( # noqa: PLR0913 - Comprehensive filter relaxation require # Stop if we exceed hard maximum if current_flex > MAX_FLEX_HARD_LIMIT: - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%s Reached 50%% flex hard limit", INDENT_L2, ) @@ -436,7 +437,7 @@ def relax_all_prices( # noqa: PLR0913 - Comprehensive filter relaxation require # Try current flex with level="any" (in relaxation mode) if original_level_filter != "any": - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%s Flex=%.1f%%: OVERRIDING level_filter: %s → ANY", INDENT_L2, current_flex * 100, @@ -450,7 +451,7 @@ def relax_all_prices( # noqa: PLR0913 - Comprehensive filter relaxation require ) phase_label_full = f"flex={current_flex * 100:.1f}% +level_any" - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%s Trying %s: config has %d intervals (all days together), level_filter=%s", INDENT_L2, phase_label_full, @@ -462,7 +463,7 @@ def relax_all_prices( # noqa: PLR0913 - Comprehensive filter relaxation require result = calculate_periods(all_prices, config=relaxed_config, time=time) new_periods = result["periods"] - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%s %s: calculate_periods returned %d periods", INDENT_L2, phase_label_full, @@ -494,7 +495,7 @@ def relax_all_prices( # noqa: PLR0913 - Comprehensive filter relaxation require if period_count >= min_periods: days_meeting_requirement += 1 - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%s Day %s: %d periods%s", INDENT_L2, day, @@ -503,7 +504,7 @@ def relax_all_prices( # noqa: PLR0913 - Comprehensive filter relaxation require ) total_periods = len(combined) - _LOGGER.debug( + _LOGGER_DETAILS.debug( "%s %s: found %d periods total, %d/%d days meet requirement", INDENT_L2, phase_label_full,