Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
56 changes: 49 additions & 7 deletions custom_components/smart_irrigation/__init__.py
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,14 @@
STATE_UNAVAILABLE,
STATE_UNKNOWN,
)
from homeassistant.core import Event, HomeAssistant, State, asyncio, callback
from homeassistant.core import (
Event,
HomeAssistant,
State,
SupportsResponse,
asyncio,
callback,
)
from homeassistant.helpers import (
config_validation as cv,
)
Expand All @@ -39,6 +46,7 @@
from homeassistant.util.unit_system import METRIC_SYSTEM

from . import const
from .calc_log import CalculationLogger
from .calculation import CalculationMixin
from .exceptions import SmartIrrigationError
from .helpers import (
Expand Down Expand Up @@ -486,6 +494,14 @@ def __init__(
self._latitude = self._effective_latitude
self._elevation = self._effective_elevation

# Calculation audit log (#12): opt-in JSONL record of every calculation.
# ``_mapping_audits`` holds the aggregation audit of each sensor group
# until the zone calculation that consumes it, ``_pending_calc_record``
# the record being assembled for the zone currently being calculated.
self.calc_logger = CalculationLogger(hass)
self._mapping_audits = {}
self._pending_calc_record = None

self._subscriptions = []

self._subscriptions.append(
Expand Down Expand Up @@ -1807,10 +1823,14 @@ async def async_update_zone_config(
zone_id: The ID of the zone to update or delete.
data: The configuration data for the mapping.

Returns:
The calculation result for the calculate branches, None otherwise.

"""
_LOGGER.debug("[async_update_zone_config]: updating zone %s", zone_id)
if data is None:
data = {}
result = None
if zone_id is not None:
zone_id = int(zone_id)
if const.ATTR_REMOVE in data:
Expand All @@ -1826,6 +1846,9 @@ async def async_update_zone_config(
_LOGGER.info("Calculating zone %s", zone_id)
if data is not None:
data.pop(const.ATTR_CALCULATE)
dry_run = data.get(const.ATTR_DRY_RUN, False)
# Forwarded as-is: async_calculate_zone is what enforces that a dry run
# does not consume the collected data.
delete_weather_data = data.get(const.ATTR_DELETE_WEATHER_DATA, True)

# aggregate sensor data
Expand All @@ -1834,7 +1857,9 @@ async def async_update_zone_config(
mapping_id = zone[const.ZONE_MAPPING]
mapping = self.store.get_mapping(mapping_id)
if mapping.get(const.MAPPING_DATA):
weatherdata = await self.apply_aggregates_to_mapping_data(mapping)
weatherdata = await self.apply_aggregates_to_mapping_data(
mapping, dry_run=dry_run
)
else:
_LOGGER.error(
"[async_update_zone_config] Error calculating zone %s: no sensor data available",
Expand All @@ -1858,14 +1883,23 @@ async def async_update_zone_config(
)
return

await self.async_calculate_zone(
zone_id, weatherdata, forecastdata, delete_weather_data
result = await self.async_calculate_zone(
zone_id, weatherdata, forecastdata, delete_weather_data, dry_run
)
if dry_run:
# Nothing was written, so there is no new start event to register
# and no valve subscription to refresh.
return result
elif const.ATTR_CALCULATE_ALL in data:
# calculate all zones
_LOGGER.info("Calculating all zones")
dry_run = data.get(const.ATTR_DRY_RUN, False)
_LOGGER.info("Calculating all zones (dry_run=%s)", dry_run)
data.pop(const.ATTR_CALCULATE_ALL)
await self._async_calculate_all(delete_weather_data=True)
result = await self._async_calculate_all(
delete_weather_data=True, dry_run=dry_run
)
if dry_run:
return result

elif const.ATTR_UPDATE in data:
_LOGGER.info("Updating zone %s", zone_id)
Expand Down Expand Up @@ -1905,6 +1939,8 @@ async def async_update_zone_config(
# A zone's linked valve entity may have changed; refresh the observer.
await self.async_setup_observed_watering()

return result

async def async_get_all_modules(self):
"""Get all ModuleEntries."""
res = []
Expand Down Expand Up @@ -1997,13 +2033,19 @@ def register_services(hass: HomeAssistant):

coordinator = hass.data[const.DOMAIN]["coordinator"]

# These two support an optional response so `dry_run: true` can report what
# the calculation would have done without writing anything.
hass.services.async_register(
const.DOMAIN,
const.SERVICE_CALCULATE_ALL_ZONES,
coordinator.handle_calculate_all_zones,
supports_response=SupportsResponse.OPTIONAL,
)
hass.services.async_register(
const.DOMAIN, const.SERVICE_CALCULATE_ZONE, coordinator.handle_calculate_zone
const.DOMAIN,
const.SERVICE_CALCULATE_ZONE,
coordinator.handle_calculate_zone,
supports_response=SupportsResponse.OPTIONAL,
)

hass.services.async_register(
Expand Down
176 changes: 176 additions & 0 deletions custom_components/smart_irrigation/calc_log.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,176 @@
"""Calculation audit log: one JSON Lines record per zone calculation (#12).

A calculation is a black box once it has run: the only introspection available
is ``_LOGGER.debug`` output, which has to be enabled *before* the interesting
day, is interleaved with the rest of the Home Assistant log, and does not
correlate the sensor-group aggregation with the equation that consumed it.

This module writes the complete chain -- raw inputs, aggregates and the
aggregation method used, module intermediates, and the resulting bucket and
duration -- to ``<config>/smart_irrigation/calc_log.jsonl``, one record per
line. Two days can then be diffed with ``jq`` or pandas instead of being
reconstructed by hand.

The feature is opt-in (a switch in the general settings) and bounded: the file
is rotated at ``CALC_LOG_MAX_BYTES`` and a single backup is kept, so it can be
left on for a whole season. Writes never raise into the calculation: a failing
audit log must not stop a zone from being watered.
"""

from __future__ import annotations

import json
import logging
import os
from datetime import datetime
from typing import Any

from homeassistant.core import HomeAssistant
from homeassistant.util import dt as dt_util

from . import const

_LOGGER = logging.getLogger(__name__)

# Keys that carry personal-ish data and are dropped or rounded before the log
# is attached to a diagnostics download.
_REDACTED_PLACEHOLDER = "[redacted]"


class CalculationLogger:
"""Append-only, size-capped JSON Lines log of calculations."""

def __init__(self, hass: HomeAssistant) -> None:
"""Initialize the logger for this Home Assistant instance."""
self._hass = hass
# str(): the path is only ever used for file operations, and tolerating
# a non-string here keeps constructing the coordinator harmless in tests
# that hand it a hass double.
self._dir = str(hass.config.path(const.CALC_LOG_DIR))
self._path = os.path.join(self._dir, const.CALC_LOG_FILENAME)

@property
def path(self) -> str:
"""Full path of the log file (it may not exist yet)."""
return self._path

@property
def backup_path(self) -> str:
"""Full path of the rotated backup file."""
return self._path + ".1"

def is_enabled(self, config: dict | None) -> bool:
"""Return whether logging is enabled in the given store config."""
if not config:
return False
return bool(
config.get(const.CONF_CALC_LOG_ENABLED, const.CONF_DEFAULT_CALC_LOG_ENABLED)
)

async def async_log(self, record: dict[str, Any]) -> None:
"""Append a record. Never raises: audit logging is not worth a failure."""
try:
line = json.dumps(record, default=_json_default, sort_keys=False)
except (TypeError, ValueError) as err:
_LOGGER.warning("[calc_log] could not serialize record: %s", err)
return
try:
await self._hass.async_add_executor_job(self._append, line)
except OSError as err:
_LOGGER.warning("[calc_log] could not write to %s: %s", self._path, err)

def _append(self, line: str) -> None:
"""Write one line, rotating first if the file grew past the cap."""
os.makedirs(self._dir, exist_ok=True)
try:
size = os.path.getsize(self._path)
except OSError:
size = 0
if size >= const.CALC_LOG_MAX_BYTES:
# Keep exactly one backup, so disk use stays bounded at 2x the cap.
os.replace(self._path, self.backup_path)
size = 0
with open(self._path, "a", encoding="utf-8") as fptr:
# A write interrupted by a crash leaves a line without its newline;
# start a new one rather than appending onto it, so a single torn
# line cannot swallow the record that follows it.
if size and not self._ends_with_newline():
fptr.write("\n")
fptr.write(line + "\n")

def _ends_with_newline(self) -> bool:
"""Whether the log file currently ends on a complete line."""
try:
with open(self._path, "rb") as fptr:
fptr.seek(-1, os.SEEK_END)
return fptr.read(1) == b"\n"
except OSError:
return True

async def async_read_recent(self, limit: int) -> list[dict[str, Any]]:
"""Return the ``limit`` most recent records, oldest first."""
try:
return await self._hass.async_add_executor_job(self._read_recent, limit)
except OSError as err:
_LOGGER.warning("[calc_log] could not read %s: %s", self._path, err)
return []

def _read_recent(self, limit: int) -> list[dict[str, Any]]:
"""Read the tail of the log, falling back to the backup when short."""
lines: list[str] = []
for path in (self.backup_path, self._path):
if not os.path.isfile(path):
continue
with open(path, encoding="utf-8") as fptr:
lines.extend(fptr.readlines())
records = []
for line in lines[-limit:]:
line = line.strip()
if not line:
continue
try:
records.append(json.loads(line))
except ValueError:
# A torn last line (write interrupted) should not fail the read.
continue
return records


def _json_default(value: Any) -> Any:
"""Serialize the non-JSON types that show up in calculation data."""
if isinstance(value, datetime):
return value.isoformat()
if isinstance(value, set | frozenset):
return sorted(value)
return str(value)


def timestamps() -> dict[str, str]:
"""Local and UTC timestamps identifying when a record was produced."""
now = dt_util.now()
return {
"timestamp": now.isoformat(),
"timestamp_utc": dt_util.as_utc(now).isoformat(),
}


def redact_record(record: dict[str, Any]) -> dict[str, Any]:
"""Return a copy safe to attach to a diagnostics download.

Coordinates are rounded to one decimal (~11 km, enough to sanity-check the
latitude that drives the radiation term without pinpointing a home) and
sensor entity ids are dropped -- they name the user's devices and are not
needed to understand why a number came out the way it did.
"""
redacted = json.loads(json.dumps(record, default=_json_default))
module = redacted.get("module")
if isinstance(module, dict):
for key in ("latitude", "longitude"):
if isinstance(module.get(key), int | float):
module[key] = round(module[key], 1)
fields = redacted.get("inputs", {}).get("fields")
if isinstance(fields, dict):
for field in fields.values():
if isinstance(field, dict) and field.get("entity") is not None:
field["entity"] = _REDACTED_PLACEHOLDER
return redacted
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,10 @@ def __init__(self, hass: HomeAssistant | None, description, config=None) -> None
name="Passthrough", description=description, schema=SCHEMA, config=config
)
self._hass = hass
# Intermediates of the last calculate() call, for the calculation audit
# log (#12). The inputs are few here, but "why this number" is asked of
# the passthrough module just as often.
self.last_trace: dict | None = None

def calculate(self, et_data=None):
"""Return the input evapotranspiration value unchanged as a float.
Expand All @@ -49,16 +53,33 @@ def calculate(self, et_data=None):
if et_data is not None:
# Ensure the value is a float before returning
try:
return float(et_data)
eto = float(et_data)
except (ValueError, TypeError):
_LOGGER.error(
"Invalid non-numeric Evapotranspiration data received by Passthrough module: %s",
et_data,
)
self.last_trace = {
"module": self.name,
"et_input": et_data,
"eto": 0,
"error": "non-numeric evapotranspiration",
}
# Return 0 if conversion fails, consistent with the original else block's return
return 0
else:
_LOGGER.error(
"No Evapotranspiration data specified (et_data is None) for Passthrough module"
)
return 0
self.last_trace = {
"module": self.name,
"et_input": et_data,
"eto": eto,
}
return eto
_LOGGER.error(
"No Evapotranspiration data specified (et_data is None) for Passthrough module"
)
self.last_trace = {
"module": self.name,
"et_input": None,
"eto": 0,
"error": "no evapotranspiration provided",
}
return 0
Loading