diff --git a/Netro Sprinklers.indigoPlugin/Contents/Info.plist b/Netro Sprinklers.indigoPlugin/Contents/Info.plist index 77ede8d..08b52d5 100644 --- a/Netro Sprinklers.indigoPlugin/Contents/Info.plist +++ b/Netro Sprinklers.indigoPlugin/Contents/Info.plist @@ -3,7 +3,7 @@ PluginVersion - 2026.5.2 + 2026.5.3 ServerApiVersion 3.6 IwsApiVersion diff --git a/Netro Sprinklers.indigoPlugin/Contents/Server Plugin/device_handlers.py b/Netro Sprinklers.indigoPlugin/Contents/Server Plugin/device_handlers.py index 21baf69..fba1441 100644 --- a/Netro Sprinklers.indigoPlugin/Contents/Server Plugin/device_handlers.py +++ b/Netro Sprinklers.indigoPlugin/Contents/Server Plugin/device_handlers.py @@ -25,6 +25,7 @@ """ import logging +import time from datetime import datetime, timezone from operator import itemgetter from typing import Any, Dict, List, Optional, Tuple @@ -32,6 +33,8 @@ from constants import V2_ONLINE_STATUSES from utils import get_key_from_dict +_MODULE_LOGGER = logging.getLogger(__name__) + __all__ = ["SprinklerHandler", "WhispererHandler", "ZoneHandler"] @@ -167,9 +170,15 @@ def process_schedules( earliest_start_time: Optional[float] = None for sch_dict in all_schedules: - # Find currently executing schedule - if sch_dict.get("status") == "EXECUTING": + # Find currently executing schedule (guard against stale + # EXECUTING entries left behind by Netro cloud) + if self._schedule_actually_executing(sch_dict, api_version): current_schedule_dict = sch_dict + elif sch_dict.get("status") == "EXECUTING": + self.logger.debug( + "Ignoring stale EXECUTING schedule id=%s zone=%s end_time=%s", + sch_dict.get("id"), sch_dict.get("zone"), sch_dict.get("end_time"), + ) # Find next valid (upcoming) schedule with earliest start time elif sch_dict.get("status") == "VALID": start_time = self._parse_schedule_sort_key( @@ -228,9 +237,45 @@ def _parse_schedule_sort_key(raw_value: Any, api_version: str = "1") -> float: else: # V1: Millisecond timestamp (may be string) return float(raw_value) if isinstance(raw_value, str) else float(raw_value) - except (ValueError, TypeError): + except (ValueError, TypeError) as exc: + _MODULE_LOGGER.debug( + "Unparseable Netro timestamp %r (api v%s): %s", + raw_value, api_version, exc, + ) return float('inf') # Unparseable schedules sort last (never "next") + @staticmethod + def _schedule_actually_executing( + schedule: Dict[str, Any], + api_version: str = "1", + ) -> bool: + """Check if an EXECUTING schedule is truly still running. + + Why: Netro cloud sometimes leaves a completed schedule marked + EXECUTING long after its end_time has passed (seen with MANUAL + runs). Trusting status alone leaves the controller's activeZone + and the zone's isIrrigating state stuck on True for days. + + Returns True if status is "EXECUTING" and either the end_time + is missing/unparseable (fall back to trusting status) or the + end_time is in the future. Returns False for a "stale" EXECUTING + whose end_time has already passed. + """ + if not isinstance(schedule, dict): + return False # malformed entry — caller should not act on it + if schedule.get("status") != "EXECUTING": + return False + end_raw = schedule.get("end_time") + if end_raw in (None, ""): + return True # can't verify — trust cloud + end_seconds = SprinklerHandler._parse_schedule_sort_key(end_raw, api_version) + if end_seconds == float('inf'): + return True # unparseable — trust cloud + if api_version != "2": + # V1 returned raw ms; convert to seconds for comparison + end_seconds = end_seconds / 1000.0 + return end_seconds > time.time() + def _format_next_schedule( self, schedule_dict: Dict[str, Any], @@ -617,7 +662,21 @@ def process_zone_schedules(self, api_response, zone_number, api_version="1"): for sch in zone_schedules: status = sch.get("status", "") if status == "EXECUTING": - is_irrigating = True + if SprinklerHandler._schedule_actually_executing(sch, api_version): + is_irrigating = True + else: + # Stale EXECUTING (end_time in past) — Netro left it stuck. + # Demote to a completed-schedule record so the zone's + # lastWatering* fields still show when the run happened. + # Overwrite status so the UI doesn't say "Last watering: + # Executing" for a watering that has actually ended. + self.logger.debug( + "Ignoring stale EXECUTING schedule id=%s zone=%s end_time=%s", + sch.get("id"), sch.get("zone"), sch.get("end_time"), + ) + if last_schedule is None or sch.get("id", 0) > last_schedule.get("id", 0): + last_schedule = dict(sch) + last_schedule["status"] = "EXECUTED" elif status in ("EXECUTED", "CANCELLED"): if last_schedule is None or sch.get("id", 0) > last_schedule.get("id", 0): last_schedule = sch diff --git a/tests/conftest.py b/tests/conftest.py index e279692..da2593e 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -160,9 +160,9 @@ def sample_v2_schedules(): { "id": 100, "zone": 1, - "start_time": "2026-04-07T06:00:00", - "end_time": "2026-04-07T06:15:00", - "local_date": "2026-04-07", + "start_time": "2099-04-07T06:00:00", + "end_time": "2099-04-07T06:15:00", + "local_date": "2099-04-07", "local_start_time": "06:00:00", "local_end_time": "06:15:00", "source": "SMART", diff --git a/tests/test_device_handlers.py b/tests/test_device_handlers.py index aca4693..b1da9f7 100644 --- a/tests/test_device_handlers.py +++ b/tests/test_device_handlers.py @@ -509,6 +509,143 @@ def test_process_schedules_duration_conversion(self, sprinkler_handler, sample_s # 1200 seconds = 20 minutes assert next_duration["value"] == 20 + def test_process_schedules_stale_executing_past_end_time_v1(self, sprinkler_handler): + """V1: EXECUTING schedule with past end_time → no active schedule.""" + response = { + "status": "OK", + "data": { + "schedules": [ + { + "status": "EXECUTING", "zone": 1, "source": "MANUAL", + "start_time": 1000000000 * 1000, + "end_time": 1000000900 * 1000, + "zone_name": "Stale", + } + ] + } + } + states, active_name = sprinkler_handler.process_schedules(response) + active_schedule = next(s for s in states if s["key"] == "activeSchedule") + active_zone = next(s for s in states if s["key"] == "activeZone") + assert active_schedule["value"] == "No active schedule" + assert active_zone["value"] == 0 + assert active_name is None + + def test_process_schedules_stale_executing_past_end_time_v2(self, sprinkler_handler): + """V2: EXECUTING schedule with past end_time → no active schedule.""" + response = { + "status": "OK", + "data": { + "schedules": [ + { + "status": "EXECUTING", "zone": 1, "source": "MANUAL", + "start_time": "2000-01-01T00:00:00", + "end_time": "2000-01-01T00:10:00", + "zone_name": "Front Garden", + } + ] + } + } + states, active_name = sprinkler_handler.process_schedules( + response, api_version="2" + ) + active_zone = next(s for s in states if s["key"] == "activeZone") + assert active_zone["value"] == 0 + assert active_name is None + + def test_process_schedules_executing_future_end_time_still_active(self, sprinkler_handler): + """Genuinely-running schedule (end_time in future) is still active.""" + response = { + "status": "OK", + "data": { + "schedules": [ + { + "status": "EXECUTING", "zone": 4, "source": "MANUAL", + "start_time": 9999999000 * 1000, + "end_time": 9999999900 * 1000, + "zone_name": "Lawn", + } + ] + } + } + states, active_name = sprinkler_handler.process_schedules(response) + active_zone = next(s for s in states if s["key"] == "activeZone") + assert active_zone["value"] == 4 + assert active_name == "Manual" + + def test_process_schedules_prefers_genuine_over_stale_executing(self, sprinkler_handler): + """With stale + genuine EXECUTING in same payload, pick the genuine one.""" + response = { + "status": "OK", + "data": { + "schedules": [ + { + "status": "EXECUTING", "zone": 1, "source": "MANUAL", + "start_time": 1000000000 * 1000, + "end_time": 1000000900 * 1000, + "zone_name": "Stale", + }, + { + "status": "EXECUTING", "zone": 4, "source": "AUTOMATIC", + "start_time": 9999999000 * 1000, + "end_time": 9999999900 * 1000, + "zone_name": "Real", + }, + ] + } + } + states, active_name = sprinkler_handler.process_schedules(response) + active_zone = next(s for s in states if s["key"] == "activeZone") + assert active_zone["value"] == 4 + assert active_name == "Automatic" + + def test_process_schedules_stale_executing_v2_tz_aware(self, sprinkler_handler): + """V2 ISO with explicit +00:00 offset is handled and compared correctly.""" + response = { + "status": "OK", + "data": { + "schedules": [ + { + "status": "EXECUTING", "zone": 1, "source": "MANUAL", + "start_time": "2000-01-01T00:00:00+00:00", + "end_time": "2000-01-01T00:10:00+00:00", + "zone_name": "Front Garden", + } + ] + } + } + states, active_name = sprinkler_handler.process_schedules( + response, api_version="2" + ) + active_zone = next(s for s in states if s["key"] == "activeZone") + assert active_zone["value"] == 0 + assert active_name is None + + def test_schedule_actually_executing_non_dict_schedule(self): + """Malformed schedules array entry (non-dict) is treated as not-executing.""" + from device_handlers import SprinklerHandler + assert SprinklerHandler._schedule_actually_executing(None) is False + assert SprinklerHandler._schedule_actually_executing("not-a-dict") is False + assert SprinklerHandler._schedule_actually_executing(42) is False + + def test_schedule_actually_executing_time_boundary(self, monkeypatch): + """End_time exactly at or before now is stale; strictly greater is live.""" + from device_handlers import SprinklerHandler + fixed_now = 1_700_000_000.0 + monkeypatch.setattr("device_handlers.time.time", lambda: fixed_now) + # One second before now — stale + assert SprinklerHandler._schedule_actually_executing({ + "status": "EXECUTING", "end_time": (fixed_now - 1) * 1000, + }) is False + # Exactly now — stale (strict >) + assert SprinklerHandler._schedule_actually_executing({ + "status": "EXECUTING", "end_time": fixed_now * 1000, + }) is False + # One second after — live + assert SprinklerHandler._schedule_actually_executing({ + "status": "EXECUTING", "end_time": (fixed_now + 1) * 1000, + }) is True + # ------------------------------------------------------------------------- # Malformed JSON Tests (TEST-04) # ------------------------------------------------------------------------- diff --git a/tests/test_zone_handler.py b/tests/test_zone_handler.py index 481d673..cad8f8e 100644 --- a/tests/test_zone_handler.py +++ b/tests/test_zone_handler.py @@ -73,7 +73,7 @@ def sample_schedules_response(): "schedules": [ { "id": 100, "zone": 1, "zone_name": "Lawn", - "start_time": 1700000000000, "end_time": 1700000900000, + "start_time": 4070908800000, "end_time": 4070909700000, "duration": 900, "source": "SMART", "status": "EXECUTING" }, { @@ -189,6 +189,130 @@ def test_v2_timestamps(self, zone_handler, sample_v2_schedules_response): assert state_dict["nextWateringSource"] == "Fix" +class TestStuckExecutingSchedule: + """Regression: Netro sometimes leaves a completed schedule marked EXECUTING. + + If its end_time is in the past, the zone isn't really irrigating and the + schedule should be treated as completed (moved to lastWatering*). + """ + + def _response(self, schedule): + return {"data": {"schedules": [schedule]}} + + def test_executing_with_past_end_time_v1_not_irrigating(self, zone_handler): + past_start_ms = 1000000000 * 1000 + past_end_ms = 1000000900 * 1000 + states = zone_handler.process_zone_schedules( + self._response({ + "id": 100, "zone": 1, + "start_time": past_start_ms, "end_time": past_end_ms, + "source": "MANUAL", "status": "EXECUTING", + }), + zone_number=1, + ) + state_dict = {s["key"]: s["value"] for s in states} + assert state_dict["isIrrigating"] is False + assert state_dict["lastWateringSource"] == "Manual" + # Demoted stale EXECUTING is relabelled so the UI doesn't show + # "Last watering: Executing" for a run that has actually ended. + assert state_dict["lastWateringStatus"] == "Executed" + + def test_executing_with_past_end_time_v2_not_irrigating(self, zone_handler): + states = zone_handler.process_zone_schedules( + self._response({ + "id": 513114600, "zone": 1, + "start_time": "2000-01-01T00:00:00", + "end_time": "2000-01-01T00:10:00", + "source": "MANUAL", "status": "EXECUTING", + }), + zone_number=1, + api_version="2", + ) + state_dict = {s["key"]: s["value"] for s in states} + assert state_dict["isIrrigating"] is False + assert "2000-01-01" in state_dict["lastWateringStart"] + assert state_dict["lastWateringSource"] == "Manual" + assert state_dict["lastWateringStatus"] == "Executed" + + def test_executing_with_future_end_time_still_irrigating(self, zone_handler): + future_start_ms = 9999999000 * 1000 + future_end_ms = 9999999900 * 1000 + states = zone_handler.process_zone_schedules( + self._response({ + "id": 100, "zone": 1, + "start_time": future_start_ms, "end_time": future_end_ms, + "source": "MANUAL", "status": "EXECUTING", + }), + zone_number=1, + ) + state_dict = {s["key"]: s["value"] for s in states} + assert state_dict["isIrrigating"] is True + + def test_executing_with_missing_end_time_trusts_status(self, zone_handler): + states = zone_handler.process_zone_schedules( + self._response({ + "id": 100, "zone": 1, + "start_time": 1000000000 * 1000, + "source": "MANUAL", "status": "EXECUTING", + }), + zone_number=1, + ) + state_dict = {s["key"]: s["value"] for s in states} + assert state_dict["isIrrigating"] is True + + def test_executing_with_unparseable_end_time_trusts_status(self, zone_handler): + """Malformed end_time (unparseable string) falls back to trusting status.""" + states = zone_handler.process_zone_schedules( + self._response({ + "id": 100, "zone": 1, + "start_time": 1000000000 * 1000, "end_time": "not-a-timestamp", + "source": "MANUAL", "status": "EXECUTING", + }), + zone_number=1, + ) + state_dict = {s["key"]: s["value"] for s in states} + assert state_dict["isIrrigating"] is True + + def test_stale_and_genuine_executing_same_zone_is_irrigating(self, zone_handler): + """If any EXECUTING for a zone is still live, isIrrigating is True.""" + response = {"data": {"schedules": [ + {"id": 100, "zone": 1, "source": "MANUAL", "status": "EXECUTING", + "start_time": 1000000000 * 1000, "end_time": 1000000900 * 1000}, + {"id": 101, "zone": 1, "source": "AUTOMATIC", "status": "EXECUTING", + "start_time": 9999999000 * 1000, "end_time": 9999999900 * 1000}, + ]}} + states = zone_handler.process_zone_schedules(response, zone_number=1) + state_dict = {s["key"]: s["value"] for s in states} + assert state_dict["isIrrigating"] is True + + def test_stale_executing_wins_id_comparison_over_older_executed(self, zone_handler): + """Demoted stale EXECUTING (id=100) beats older EXECUTED (id=99) by id.""" + response = {"data": {"schedules": [ + {"id": 99, "zone": 1, "source": "SMART", "status": "EXECUTED", + "start_time": 900000000 * 1000, "end_time": 900000900 * 1000}, + {"id": 100, "zone": 1, "source": "MANUAL", "status": "EXECUTING", + "start_time": 1000000000 * 1000, "end_time": 1000000900 * 1000}, + ]}} + states = zone_handler.process_zone_schedules(response, zone_number=1) + state_dict = {s["key"]: s["value"] for s in states} + assert state_dict["isIrrigating"] is False + assert state_dict["lastWateringSource"] == "Manual" + + def test_newer_executed_wins_id_comparison_over_stale_executing(self, zone_handler): + """Real EXECUTED (id=200) beats demoted stale EXECUTING (id=100) by id.""" + response = {"data": {"schedules": [ + {"id": 100, "zone": 1, "source": "MANUAL", "status": "EXECUTING", + "start_time": 1000000000 * 1000, "end_time": 1000000900 * 1000}, + {"id": 200, "zone": 1, "source": "SMART", "status": "EXECUTED", + "start_time": 1100000000 * 1000, "end_time": 1100000900 * 1000}, + ]}} + states = zone_handler.process_zone_schedules(response, zone_number=1) + state_dict = {s["key"]: s["value"] for s in states} + assert state_dict["isIrrigating"] is False + assert state_dict["lastWateringSource"] == "Smart" + assert state_dict["lastWateringStatus"] == "Executed" + + @pytest.fixture def sample_moistures_response(): return {