diff --git a/.cspell/custom-dictionary-workspace.txt b/.cspell/custom-dictionary-workspace.txt index 9dce572c6..4cd885673 100644 --- a/.cspell/custom-dictionary-workspace.txt +++ b/.cspell/custom-dictionary-workspace.txt @@ -42,6 +42,7 @@ autoflake automations autopep autoupdate +axisbelow axvline axvspan Backfeed @@ -173,6 +174,7 @@ echargingpile ecosmart Eddi eddis +edgecolor efgh elif elinter @@ -216,6 +218,7 @@ exog expmsg exportlimit exportvalue +facecolor fdpwr fdsoc feedin @@ -235,6 +238,7 @@ formmethod foxcloud foxess foxesscloud +frameon freephase fromisoformat fronius @@ -265,6 +269,7 @@ gridcharge gridcode gridconsumption gridconsumptionpower +gridspec Groq growatt growattsph @@ -424,6 +429,7 @@ nanstd nattribute nbytes ncalls +ncol nearr nemotron NESO @@ -585,6 +591,7 @@ setpoints setstate SFMB sg05lp1 +sharex SIGALRM sigcloud sigen @@ -637,6 +644,7 @@ substep sunspec sunsynk supabase +suptitle suspendedev suspendedevse synkctl @@ -749,7 +757,9 @@ yaxis yaxistooltip yday ylabel +ylim YOURSERIAL +yticks yuanzhi zappi zappis diff --git a/apps/predbat/components.py b/apps/predbat/components.py index 9e7835290..e55adfe54 100644 --- a/apps/predbat/components.py +++ b/apps/predbat/components.py @@ -636,6 +636,20 @@ def load_component_class(component_info): "phase": 1, "can_restart": True, }, + "dummy_inverter": { + "class": "dummy_inverter.DummyInverter", + "name": "Dummy Inverter", + "inverter": True, + "event_filter": "predbat_dummy_", + # A simulated inverter and battery for demos and log replay, enabled by a dummy_inverter apps.yaml block. + # Defaults for every setting in the block live in dummy_inverter.py beside the model that uses them. + "args": { + "config": {"required": True, "config": "dummy_inverter"}, + "automatic": {"required": False, "config": "dummy_inverter_automatic", "default": True}, + }, + "phase": 1, + "can_restart": True, + }, "teslemetry": { "class": "teslemetry.TeslemetryAPI", "name": "Tesla Powerwall (Teslemetry)", diff --git a/apps/predbat/config.py b/apps/predbat/config.py index 6aef46e77..b230da077 100644 --- a/apps/predbat/config.py +++ b/apps/predbat/config.py @@ -2513,6 +2513,35 @@ "charge_discharge_with_rate": False, "target_soc_used_for_discharge": False, }, + "DUMMY": { + "name": "Dummy (simulated)", + "has_rest_api": False, + "has_mqtt_api": False, + "output_charge_control": "power", + "charge_control_immediate": False, + "has_charge_enable_time": True, + "has_discharge_enable_time": True, + "has_target_soc": True, + "has_reserve_soc": True, + "has_timed_pause": False, + "charge_time_format": "HH:MM:SS", + "charge_time_entity_is_option": True, + "soc_units": "%", + "num_load_entities": 1, + "has_ge_inverter_mode": False, + "has_ge_eco_toggle": False, + "time_button_press": False, + "clock_time_format": "%Y-%m-%d %H:%M:%S", + "write_and_poll_sleep": 2, + "has_time_window": False, + "support_charge_freeze": True, + "support_discharge_freeze": True, + "support_feedin_first": False, + "has_idle_time": False, + "can_span_midnight": True, + "charge_discharge_with_rate": False, + "target_soc_used_for_discharge": False, + }, "GWMQTT": { "name": "ESP32 Gateway MQTT", "has_rest_api": False, diff --git a/apps/predbat/dummy_inverter.py b/apps/predbat/dummy_inverter.py new file mode 100644 index 000000000..91130d847 --- /dev/null +++ b/apps/predbat/dummy_inverter.py @@ -0,0 +1,408 @@ +# ----------------------------------------------------------------------------- +# Predbat Home Battery System +# Copyright Trefor Southwell 2026 - All Rights Reserved +# This application maybe used for personal use only and not for commercial use +# ----------------------------------------------------------------------------- +# fmt off +# pylint: disable=consider-using-f-string +# pylint: disable=line-too-long +# pylint: disable=attribute-defined-outside-init +"""A simulated inverter and battery, for demonstrating Predbat and for replaying logs. + +The component publishes the same kind of sensors and controls a cloud inverter component does, and wires +Predbat to them with automatic_config, so Predbat plans and controls it exactly as it would a real one. Behind +those entities sits a minute-by-minute model of a hybrid inverter with a battery: the battery charges and +discharges within its rate limits and losses, PV and battery share the inverter's AC limit, export is capped +at the export limit, and PV that cannot go anywhere is clipped. Charge and export windows written by Predbat +are obeyed; outside them the inverter runs self-consumption (Eco). + +PV comes from Predbat's own forecast when it has one, otherwise from a simple clear-sky curve; load is a +constant or an hourly profile. Every setting lives in one apps.yaml block: + + dummy_inverter: + battery_size: 10 # kWh usable + battery_rate_max: 3600 # W, charge and discharge + inverter_limit: 5000 # W, AC output shared by PV and battery + export_limit: 5000 # W + battery_loss: 0.96 # charge efficiency + battery_loss_discharge: 0.96 + inverter_loss: 0.96 # AC <-> DC conversion for the battery + reserve: 4 # % + soc_initial: 50 # % + pv_peak: 4.0 # kW, clear-sky curve peak when there is no forecast + pv_scaling: 1.0 # applied to the forecast or curve + load: 0.4 # kW constant, or a list of 24 hourly kW values + +The model is deliberately independent of Predbat's prediction engine, so it can catch a prediction that +disagrees with what an inverter would actually do. +""" +import math +from datetime import datetime, timedelta + +from component_base import ComponentBase + +DUMMY_DEFAULTS = { + "battery_size": 10.0, + "battery_rate_max": 3600.0, + "inverter_limit": 5000.0, + "export_limit": 5000.0, + "battery_loss": 0.96, + "battery_loss_discharge": 0.96, + "inverter_loss": 0.96, + "reserve": 4.0, + "soc_initial": 50.0, + "pv_peak": 4.0, + "pv_scaling": 1.0, + "sunrise": 6.5, + "sunset": 18.5, + "load": 0.4, +} + +DUMMY_OPTIONS_TIME = [(datetime(2000, 1, 1) + timedelta(minutes=minute)).strftime("%H:%M:%S") for minute in range(0, 24 * 60)] + +# Never simulate more than this many minutes in one go, so a long stall (a suspended laptop) does not +# spend minutes replaying a day the user did not see +MAX_CATCH_UP_MINUTES = 60 + +# The capabilities the simulated inverter has, mirroring INVERTER_DEF["DUMMY"] in config.py +DUMMY_CAPABILITIES = { + "support_charge_freeze": True, + "support_discharge_freeze": True, + "support_feedin_first": False, + "can_span_midnight": True, + "charge_discharge_with_rate": False, + "charge_control_immediate": False, + "target_soc_used_for_discharge": False, +} + + +def time_to_minute(text): + """Convert HH:MM or HH:MM:SS to minutes past midnight, or None if it cannot be read.""" + try: + parts = str(text).split(":") + return int(parts[0]) * 60 + int(parts[1]) + except (ValueError, IndexError): + return None + + +def in_window(minute_of_day, start_text, end_text): + """True when minute_of_day falls in the window [start, end), which may run past midnight.""" + start = time_to_minute(start_text) + end = time_to_minute(end_text) + if start is None or end is None or start == end: + return False + if start < end: + return start <= minute_of_day < end + return minute_of_day >= start or minute_of_day < end + + +def simulate_minute(params, controls, soc_kwh, pv_kw, load_kw, minute_of_day): + """Advance the battery by one minute and return the new SoC and the minute's power flows. + + params are the configured limits and losses (DUMMY_DEFAULTS keys); controls are the charge/export windows + and reserve as Predbat writes them. Returns (soc_kwh, flows) where flows holds kW for the minute: + battery (+ discharging, - charging), grid (+ importing, - exporting), pv (as produced, after clipping), + load, and clipped (PV that was available but could not be used). + + The battery sits on the DC side with the PV, so PV charging the battery does not pass through the inverter; + battery discharge and grid charging do, and pay inverter_loss. The inverter's AC output - PV not going to the + battery, plus battery discharge - never exceeds inverter_limit, with PV taking priority, as observed on real + hybrids. Grid export never exceeds export_limit; anything PV still cannot place is clipped. + """ + hours = 1.0 / 60.0 + soc_max = params["battery_size"] + rate_max = params["battery_rate_max"] / 1000.0 + inverter_limit = params["inverter_limit"] / 1000.0 + export_limit = params["export_limit"] / 1000.0 + reserve_kwh = soc_max * float(controls.get("reserve", params["reserve"])) / 100.0 + charge = controls.get("charge", {}) + export = controls.get("export", {}) + + charging = charge.get("enable") and in_window(minute_of_day, charge.get("start_time"), charge.get("end_time")) + exporting = export.get("enable") and in_window(minute_of_day, export.get("start_time"), export.get("end_time")) + + # Room in the battery and energy above the floor, as kW that can flow for the whole minute + room_kw = max(soc_max - soc_kwh, 0.0) / hours / params["battery_loss"] + if charging: + target_kwh = soc_max * float(charge.get("target_soc", 100)) / 100.0 + room_kw = min(room_kw, max(target_kwh - soc_kwh, 0.0) / hours / params["battery_loss"]) + floor_kwh = reserve_kwh + if exporting: + floor_kwh = max(floor_kwh, soc_max * float(export.get("target_soc", 0)) / 100.0) + available_kw = max(soc_kwh - floor_kwh, 0.0) / hours * params["battery_loss_discharge"] + + battery_charge = 0.0 # kW into the battery, DC + battery_discharge = 0.0 # kW out of the battery, DC + pv_to_battery = 0.0 + grid_to_battery = 0.0 + + if charging: + # Charge at the window's rate, PV first and the grid for the rest + rate = min(float(charge.get("rate", rate_max * 1000.0)) / 1000.0, rate_max) + battery_charge = min(rate, room_kw) + pv_to_battery = min(pv_kw, battery_charge) + grid_to_battery = battery_charge - pv_to_battery + elif exporting: + # Discharge at the window's rate, within what the inverter has left after PV + rate = min(float(export.get("rate", rate_max * 1000.0)) / 1000.0, rate_max) + ac_headroom = max(inverter_limit - pv_kw, 0.0) + battery_discharge = min(rate, available_kw, ac_headroom / params["inverter_loss"]) + else: + # Eco: cover the load from PV, then the battery; surplus PV charges the battery + surplus = pv_kw - load_kw + if surplus >= 0: + battery_charge = min(surplus, rate_max, room_kw) + pv_to_battery = battery_charge + else: + ac_headroom = max(inverter_limit - pv_kw, 0.0) + battery_discharge = min(-surplus / params["inverter_loss"], rate_max, available_kw, ac_headroom / params["inverter_loss"]) + + # PV that is not charging the battery goes through the inverter, capped at the AC limit with PV first + pv_ac = pv_kw - pv_to_battery + clipped = max(pv_ac - inverter_limit, 0.0) + pv_ac -= clipped + battery_ac = battery_discharge * params["inverter_loss"] + grid_charge_ac = grid_to_battery / params["inverter_loss"] + + # Grid balances the rest: + import, - export. Export is capped; PV takes the cut, then the battery + grid = load_kw + grid_charge_ac - pv_ac - battery_ac + if grid < -export_limit: + excess = -export_limit - grid + cut_battery = min(excess, battery_ac) + battery_ac -= cut_battery + battery_discharge = battery_ac / params["inverter_loss"] + excess -= cut_battery + pv_ac -= excess + clipped += excess + grid = -export_limit + + soc_kwh = soc_kwh + battery_charge * hours * params["battery_loss"] - battery_discharge * hours / params["battery_loss_discharge"] + soc_kwh = min(max(soc_kwh, 0.0), soc_max) + flows = { + "battery": battery_discharge - battery_charge, + "grid": grid, + "pv": pv_kw - clipped, + "load": load_kw, + "clipped": clipped, + } + return soc_kwh, flows + + +def clear_sky_pv(params, minute_of_day): + """A clear-sky PV curve: a half sine between sunrise and sunset peaking at pv_peak kW.""" + hour = minute_of_day / 60.0 + sunrise, sunset = params["sunrise"], params["sunset"] + if hour <= sunrise or hour >= sunset: + return 0.0 + return params["pv_peak"] * math.sin(math.pi * (hour - sunrise) / (sunset - sunrise)) + + +def load_at(params, minute_of_day): + """The configured load at minute_of_day: a constant kW, or one of 24 hourly kW values.""" + load = params["load"] + if isinstance(load, (list, tuple)) and load: + return float(load[(minute_of_day // 60) % len(load)]) + return float(load) + + +class DummyInverter(ComponentBase): + """A simulated hybrid inverter and battery that Predbat plans and controls like a real one.""" + + def initialize(self, config=None, automatic=True, **kwargs): + """Read the dummy_inverter apps.yaml block over the defaults and set up the simulation state.""" + self.params = dict(DUMMY_DEFAULTS) + if isinstance(config, dict): + for key in DUMMY_DEFAULTS: + if key in config and config[key] is not None: + self.params[key] = config[key] if key == "load" else float(config[key]) + self.automatic = automatic + self.soc_kwh = self.params["battery_size"] * self.params["soc_initial"] / 100.0 + self.totals = {"pv": 0.0, "load": 0.0, "import": 0.0, "export": 0.0, "clipped": 0.0} + self.flows = {"battery": 0.0, "grid": 0.0, "pv": 0.0, "load": 0.0, "clipped": 0.0} + self.last_minute = None + rate_w = self.params["battery_rate_max"] + self.controls = { + "charge": {"start_time": "00:00:00", "end_time": "00:00:00", "enable": False, "target_soc": 100, "rate": rate_w}, + "export": {"start_time": "00:00:00", "end_time": "00:00:00", "enable": False, "target_soc": 0, "rate": rate_w}, + "reserve": self.params["reserve"], + } + + def entity(self, domain, name): + """Return the entity ID for one of the dummy inverter's entities.""" + return "{}.{}_dummy_{}".format(domain, self.prefix, name) + + def pv_now(self, minute_of_day): + """PV in kW: Predbat's forecast for this minute when it has one, otherwise the clear-sky curve.""" + forecast = getattr(self.base, "pv_forecast_minute", None) + if forecast and minute_of_day in forecast: + # The forecast holds kWh per minute + return max(float(forecast[minute_of_day]) * 60.0, 0.0) * self.params["pv_scaling"] + return clear_sky_pv(self.params, minute_of_day) * self.params["pv_scaling"] + + def step(self, minutes_absolute): + """Simulate from the last simulated minute up to minutes_absolute (minutes since an arbitrary epoch).""" + if self.last_minute is None: + self.last_minute = minutes_absolute + return + minutes = min(max(minutes_absolute - self.last_minute, 0), MAX_CATCH_UP_MINUTES) + for offset in range(minutes): + minute_of_day = (minutes_absolute - minutes + offset) % (24 * 60) + pv_kw = self.pv_now(minute_of_day) + load_kw = load_at(self.params, minute_of_day) + self.soc_kwh, self.flows = simulate_minute(self.params, self.controls, self.soc_kwh, pv_kw, load_kw, minute_of_day) + self.totals["pv"] += self.flows["pv"] / 60.0 + self.totals["load"] += self.flows["load"] / 60.0 + self.totals["clipped"] += self.flows["clipped"] / 60.0 + if self.flows["grid"] > 0: + self.totals["import"] += self.flows["grid"] / 60.0 + else: + self.totals["export"] += -self.flows["grid"] / 60.0 + self.last_minute = minutes_absolute + + def publish(self): + """Publish the simulated sensors.""" + soc_max = self.params["battery_size"] + sensors = [ + ("battery_soc", round(self.soc_kwh, 3), "kWh", "Battery SoC"), + ("battery_capacity", soc_max, "kWh", "Battery capacity"), + ("battery_soc_percent", round(self.soc_kwh / soc_max * 100.0, 1) if soc_max else 0, "%", "Battery SoC %"), + ("battery_power", round(self.flows["battery"] * 1000.0), "W", "Battery power"), + ("pv_power", round(self.flows["pv"] * 1000.0), "W", "PV power"), + ("load_power", round(self.flows["load"] * 1000.0), "W", "Load power"), + ("grid_power", round(self.flows["grid"] * 1000.0), "W", "Grid power"), + ("clipped_power", round(self.flows["clipped"] * 1000.0), "W", "Clipped PV power"), + ("battery_rate_max", self.params["battery_rate_max"], "W", "Battery rate max"), + ("inverter_limit", self.params["inverter_limit"], "W", "Inverter limit"), + ("export_limit", self.params["export_limit"], "W", "Export limit"), + ("pv_lifetime", round(self.totals["pv"], 3), "kWh", "PV total"), + ("load_lifetime", round(self.totals["load"], 3), "kWh", "Load total"), + ("grid_import_lifetime", round(self.totals["import"], 3), "kWh", "Grid import total"), + ("grid_export_lifetime", round(self.totals["export"], 3), "kWh", "Grid export total"), + ("clipped_lifetime", round(self.totals["clipped"], 3), "kWh", "Clipped PV total"), + ] + for name, state, unit, friendly in sensors: + attributes = {"friendly_name": "Dummy inverter {}".format(friendly), "unit_of_measurement": unit} + if unit == "kWh" and name.endswith("_lifetime"): + attributes["state_class"] = "total_increasing" + self.dashboard_item(self.entity("sensor", name), state=state, attributes=attributes, app="dummy_inverter") + self.dashboard_item(self.entity("sensor", "time"), state=self.now_utc.strftime("%Y-%m-%d %H:%M:%S"), attributes={"friendly_name": "Dummy inverter time"}, app="dummy_inverter") + + def control_info(self, direction, field): + """Return (entity_id, attributes, state) for one control, as Predbat reads and writes it.""" + values = self.controls[direction] if direction else self.controls + value = values[field] + name = "{}_{}".format(direction, field) if direction else field + friendly = "Dummy inverter {}".format(name.replace("_", " ")) + if field.endswith("_time"): + return self.entity("select", name), {"friendly_name": friendly, "options": DUMMY_OPTIONS_TIME}, value + if field == "enable": + return self.entity("switch", name), {"friendly_name": friendly}, "on" if value else "off" + if field == "rate": + return self.entity("number", name), {"friendly_name": friendly, "unit_of_measurement": "W", "min": 0, "max": self.params["battery_rate_max"], "step": 1}, value + return self.entity("number", name), {"friendly_name": friendly, "unit_of_measurement": "%", "min": 0, "max": 100, "step": 1}, value + + def control_fields(self): + """Every (direction, field) pair the dummy inverter exposes as a control.""" + fields = [(direction, field) for direction in ("charge", "export") for field in ("start_time", "end_time", "enable", "target_soc", "rate")] + return fields + [(None, "reserve")] + + def publish_controls(self): + """Publish the control entities with their current values.""" + for direction, field in self.control_fields(): + entity_id, attributes, state = self.control_info(direction, field) + self.dashboard_item(entity_id, state=state, attributes=attributes, app="dummy_inverter") + + def find_control(self, entity_id): + """Return the (direction, field) a control entity ID belongs to, or (None, None) when it is not one.""" + for direction, field in self.control_fields(): + if self.control_info(direction, field)[0] == entity_id: + return direction, field + return None, None + + def update_control(self, entity_id, value): + """Apply a write from Predbat to one control and re-publish it. Returns True when it was a dummy control.""" + direction, field = self.find_control(entity_id) + if field is None: + return False + target = self.controls[direction] if direction else self.controls + if field == "enable": + current = target[field] + target[field] = {"turn_on": True, "turn_off": False, "toggle": not current}.get(value, value in (True, "on")) + elif field.endswith("_time"): + if time_to_minute(value) is None: + self.log("Warn: DummyInverter: ignoring unreadable time {} for {}".format(value, entity_id)) + return True + target[field] = str(value) + else: + try: + target[field] = float(value) + except (TypeError, ValueError): + self.log("Warn: DummyInverter: ignoring unreadable value {} for {}".format(value, entity_id)) + return True + entity, attributes, state = self.control_info(direction, field) + self.dashboard_item(entity, state=state, attributes=attributes, app="dummy_inverter") + return True + + async def select_event(self, entity_id, value): + """Handle a select write from Predbat.""" + self.update_control(entity_id, value) + + async def number_event(self, entity_id, value): + """Handle a number write from Predbat.""" + self.update_control(entity_id, value) + + async def switch_event(self, entity_id, service): + """Handle a switch service call from Predbat.""" + self.update_control(entity_id, service) + + def automatic_config(self): + """Point Predbat's inverter settings at the dummy inverter's entities.""" + self.set_arg("num_inverters", 1) + self.set_arg("inverter_type", ["DUMMY"]) + for arg, name in ( + ("soc_kw", "battery_soc"), + ("soc_max", "battery_capacity"), + ("battery_power", "battery_power"), + ("battery_rate_max", "battery_rate_max"), + ("inverter_limit", "inverter_limit"), + ("export_limit", "export_limit"), + ("pv_power", "pv_power"), + ("grid_power", "grid_power"), + ("load_power", "load_power"), + ("pv_today", "pv_lifetime"), + ("load_today", "load_lifetime"), + ("import_today", "grid_import_lifetime"), + ("export_today", "grid_export_lifetime"), + ("inverter_time", "time"), + ): + self.set_arg(arg, [self.entity("sensor", name)]) + for arg, direction, field in ( + ("charge_start_time", "charge", "start_time"), + ("charge_end_time", "charge", "end_time"), + ("charge_limit", "charge", "target_soc"), + ("scheduled_charge_enable", "charge", "enable"), + ("charge_rate", "charge", "rate"), + ("discharge_start_time", "export", "start_time"), + ("discharge_end_time", "export", "end_time"), + ("discharge_target_soc", "export", "target_soc"), + ("scheduled_discharge_enable", "export", "enable"), + ("discharge_rate", "export", "rate"), + ("reserve", None, "reserve"), + ): + self.set_arg(arg, [self.control_info(direction, field)[0]]) + self.log("DummyInverter: automatic_config complete") + + def minutes_absolute(self): + """Whole minutes since the epoch for the current time, so the simulation can step across midnight.""" + return int(self.now_utc.timestamp() // 60) + + async def run(self, seconds, first): + """Advance the simulation to now and publish; on the first run also publish controls and wire Predbat up.""" + if first: + self.publish_controls() + if self.automatic: + self.automatic_config() + self.step(self.minutes_absolute()) + self.publish() + self.update_success_timestamp() + return True diff --git a/apps/predbat/tests/replay_forward.py b/apps/predbat/tests/replay_forward.py new file mode 100644 index 000000000..7b833f59a --- /dev/null +++ b/apps/predbat/tests/replay_forward.py @@ -0,0 +1,1220 @@ +# ----------------------------------------------------------------------------- +# Predbat Home Battery System +# Copyright Trefor Southwell 2026 - All Rights Reserved +# This application maybe used for personal use only and not for commercial use +# ----------------------------------------------------------------------------- +# fmt off +# pylint: disable=consider-using-f-string +# pylint: disable=line-too-long +# pylint: disable=attribute-defined-outside-init +"""Replay a Predbat log forwards from a debug yaml. + +A debug yaml is a single snapshot. A bug report usually also carries the log from the following hours, which +records what the battery, PV and load actually did and what each re-plan produced. This module restores the +yaml, then steps through the log one Predbat run at a time: it sets the clock, SoC, history and the inverter's +export window from the log, re-plans on the runs where the real Predbat did, and compares the export windows +it gets with the ones the log shows. + +The comparison is the point. Where the replay reproduces the logged windows it can be trusted for what-if +changes; where it does not, the first run that diverges says what the log carries that the yaml did not. + +Inputs taken from the log rather than recomputed: SoC, the cumulative load/PV/import/export counters, the +in-day load adjustment, the load divergence, the cost so far today and the inverter's programmed export window. The PV forecast is +the one in the yaml - the log records only its total. + +Newer Predbat versions also write "Replay input:" lines carrying what the human-readable lines round or leave out: +the load and PV forecasts, the plan's starting state at full precision, and the rates and car state whenever +they change. Where a +run has them they take precedence. + +The replay carries on across midnight (roll_over_midnight), so a late-evening yaml replays the whole next day. +""" +import array +import ast +import math +import re +from datetime import date, timedelta + +from const import PREDICT_STEP, EXPORT_MODE_TARGET +from utils import MinuteArray, pack_export_limit, calc_percent_limit +from prediction import Prediction +from tests.test_single_debug import restore_debug_state, rebuild_load_pv_models, rescan_rate_windows, apply_overrides + +RUN_RE = re.compile(r"PredBat - update at (\S+ \S+) with clock skew .*minutes now (\d+)") +# Inverter 0's SoC, power and percentage. Older versions wrote "SOC: 1.9kW 20% ... Current power -1134.0W" +SOC_RE = re.compile(r"Inverter 0 S[Oo][Cc]: ([\d.]+)kWh? (\d+)%.*?(?i:current) (?:battery )?power (-?[\d.]+)W") +# Every inverter's own SoC line, to total a system with several when the log has no totals line +SOC_EACH_RE = re.compile(r"Inverter (\d+) S[Oo][Cc]: ([\d.]+)kWh? (\d+)%") +# Older versions also logged the total across all inverters, which is what the plan starts from with more than one +SOC_TOTAL_RE = re.compile(r"Found \d+ inverters totals: .*?soc_max ([\d.]+) soc ([\d.]+)") +# Older versions: "load 5.04 kWh import 14.07 kWh export 0.0 kWh pv 0.0 kWh" +TODAY_RE = re.compile(r"Current data so far today: load ([\d.]+) ?kWh,? import ([\d.]+) ?kWh,? export ([\d.]+) ?kWh,? (?:PV|pv) ([\d.]+) ?kWh") +INDAY_RE = re.compile(r"in-day adjustment ([\d.]+)%") +DIVERGENCE_RE = re.compile(r"Load divergence over .* divergence ([\d.]+)%") +# The divergence fraction exactly as get_load_divergence() returns it, which the rounded percentage above can miss +DIVERGENCE_EXACT_RE = re.compile(r"Replay input: load divergence ([\d.e+-]+|None)$") +FILTERED_RE = re.compile(r"Export windows filtered (\[.*\])") +# Logged on every re-plan in every version, including those that do not log the export windows filtered +REPLAN_RE = re.compile(r"Filtered charge windows \[") +NEXT_LIMIT_RE = re.compile(r"Next export window will be: .* at reserve \((\d+), (\w+), ([\d.]+)\)") +VERSION_RE = re.compile(r"version (\S+) currently running") +# Lines written by Predbat versions that log the inputs a replay cannot otherwise recover +LOAD_INPUT_RE = re.compile(r"Replay input: load forecast, 5-minute Wh from (\d\d):(\d\d) \[([^\]]*)\]") +# The cumulative load forecast at each 5-minute step the plan builds and the minute after, exactly as the plan reads it +LOAD_EXACT_RE = re.compile(r"Replay input: load forecast, cumulative kWh at each 5-minute step and the minute after from (\d\d):(\d\d) (\[.*\])$") +# The same forecast in whole tenths of a Wh: the cumulative value at the first step, then "Wh in the step/Wh in its first minute" +LOAD_COMPACT_RE = re.compile(r"Replay input: load from (\d\d):(\d\d) base (-?[\d.]+) Wh, Wh/5min \[(.*)\]$") +PV_INPUT_RE = re.compile(r"Replay input: PV forecast changed, 30-minute kWh from (\d\d):(\d\d) p50 \[([^\]]*)\] p10 \[([^\]]*)\] p90 \[([^\]]*)\]") +# The plan's starting state, each value written so it reads back as the same float (or None) +STATE_INPUT_RE = re.compile(r"Replay input: state (.*)$") +# The rates from now, as change points, logged only when they change +RATES_INPUT_RE = re.compile(r"Replay input: rates changed, from (\d\d):(\d\d) (.*)$") +RATES_SERIES_RE = re.compile(r"(\w+) (\[\]|\[\[.*?\]\]) (\d+)") +# Rate series in the rates line and the instance attributes they replace +RATES_ATTRIBUTES = {"import": "rate_import", "export": "rate_export", "import_base": "rate_import_base", "export_base": "rate_export_base"} +# The PV forecast per minute from now to the end of the plan, exactly, as runs of [kWh per minute, minutes] +PV_EXACT_RE = re.compile(r"Replay input: PV forecast changed, per-minute kWh runs from (\d\d):(\d\d) p50 (\[.*?\]\]) p10 (\[.*?\]\]) p90 (\[.*?\]\])$") +# The inverter's programmed state, logged only when it changes, as a dict that reads back with ast.literal_eval +INVERTER_INPUT_RE = re.compile(r"Replay input: inverter changed (\{.*\})$") +# The car state the plan reads, logged only when it changes, as a dict that reads back with ast.literal_eval +CARS_INPUT_RE = re.compile(r"Replay input: cars changed (\{.*\})$") +# Human-readable lines older logs carry instead (since v5.1 and v7.0): each car's planned slots, and the planned and +# charging-now flags. Read only where a run has no exact cars line. +CAR_PLAN_RE = re.compile(r"Car (\d+) charging plan is: (\[.*\])$") +CAR_FLAGS_RE = re.compile(r"Cars \d+ charging from battery \w+ planned (\[[^\]]*\]), charging_now (\[[^\]]*\])") +# The Intelligent dispatch list as the API returned it, logged on a change (since v8.27.27) +OCTOPUS_SLOTS_RE = re.compile(r"Octopus slots changed from (\[.*\])$") +COST_RE = re.compile(r"Today's energy total net .*?, cost (-?[\d.]+)") +IN_FORCE_RE = re.compile(r"Best export window (\[.*\])") +# Logged just before it, as percent limits: the charge windows in force +IN_FORCE_CHARGE_RE = re.compile(r"Best charge window (\[.*\])") +# Logged for every recompute, whatever triggered it (a sensor change too), despite its wording +RECOMPUTE_RE = re.compile(r"Will recompute the plan as it is invalid") +# Logged by calculate_plan only when the plan really is invalid, so the new plan is adopted without comparing it to the old +INVALID_RE = re.compile(r"Recompute, previous plan is invalid") +FORCE_RE = re.compile(r"Inverter 0 Adjust force export to (True|False), change times from \S+ - \S+ to (\d+):(\d+):\d+ - (\d+):(\d+):\d+") +WINDOW_RE = re.compile(r"(\d\d-\d\d) (\d\d):(\d\d):\d\d - (\d\d-\d\d) (\d\d):(\d\d):\d\d @ ([\d.]+)\S+ ([\d.]+)%") +# The four day counters in the order the log prints them, and the history arrays that mirror them +COUNTER_ARRAYS = ("load_minutes", "import_today", "export_today", "pv_today") +# Other backwards cumulative histories read alongside the load history (the load filter subtracts car and +# iBoost energy from it). The log has no per-run figure for these, so they age with nothing added - right +# while the car is not charging and iBoost is idle, which is the case the replay supports so far. +AGED_ARRAYS = ("car_charging_energy", "iboost_energy_today") +# The midnight run goes on to plan every tariff in the comparison list, logging a full plan for each; none of +# that is the live plan, so a run stops collecting once it starts +COMPARE_RE = re.compile(r"Starting comparison of tariffs") +# State held as minutes from today's midnight. Fetch rebuilds it every run against the current midnight, so when +# the replay crosses midnight it moves back a day. plan_last_updated_minutes is deliberately left alone: once it +# is later than minutes_now, calculate_plan forces the start-of-day re-plan exactly as the live system does. +DAY_KEYED_DICTS = ( + "rate_import", + "rate_export", + "rate_gas", + "rate_import_base", + "rate_export_base", + "rate_import_no_io", + "rate_import_replicated", + "rate_export_replicated", + "rate_gas_replicated", + "rate_min_forward", + "rate_export_max_forward", + "future_energy_rates_import", + "future_energy_rates_export", + "manual_import_rates", + "manual_export_rates", + "pv_forecast_minute", + "pv_forecast_minute10", + "pv_forecast_minute90", + "pv_light_dark", + "load_scaling_dynamic", + "dynamic_load_baseline", + "carbon_intensity", + "alert_active_keep", + "manual_soc_keep", + "manual_soc_max_keep", + "all_active_keep", + "all_active_keep_max", +) +DAY_WINDOW_LISTS = ("charge_window", "export_window", "charge_window_best", "export_window_best", "low_rates", "high_export_rates", "iboost_plan") +DAY_MINUTE_LISTS = ("manual_charge_times", "manual_export_times", "manual_freeze_charge_times", "manual_freeze_export_times", "manual_demand_times", "manual_all_times") +WINDOW_MINUTE_KEYS = ("start", "end", "start_orig", "end_orig") + + +def day_offset(date_text, day): + """Days from day to date_text, both dd-mm (the plan text carries no year).""" + if not day: + return 0 + delta = (date(2000, int(date_text[3:5]), int(date_text[:2])) - date(2000, int(day[3:5]), int(day[:2]))).days + # A plan seen on 31 Dec reaches into January + if delta < -180: + delta += 366 + return delta + + +def parse_windows(text, day=None): + """Parse a window_as_text string into (start minute, end minute, rate, percent) tuples. + + Minutes are counted from midnight of day (dd-mm, the date of the run that logged or made the plan), so a + window tomorrow starts at 1440 or later and can never be mistaken for one today. + """ + windows = [] + for m in WINDOW_RE.findall(text): + start = day_offset(m[0], day) * 1440 + int(m[1]) * 60 + int(m[2]) + end = day_offset(m[3], day) * 1440 + int(m[4]) * 60 + int(m[5]) + windows.append((start, end, float(m[6]), float(m[7]))) + return windows + + +def minute_label(minute): + """Format a minute from midnight as HH:MM, marking later days with +Nd.""" + days, rest = divmod(minute, 1440) + return "{:02d}:{:02d}{}".format(rest // 60, rest % 60, "+{}d".format(days) if days else "") + + +def parse_log(path): + """Split a Predbat log into runs, one per "PredBat - update" line, keeping what the replay needs. + + Several runs can share a minutes_now (a scheduled run plus one triggered by a sensor change), so a run + is keyed by its position in the log, not by its time. A run that never logged a SoC is dropped. + """ + runs = [] + run = None + with open(path, "r", errors="replace") as handle: + for line in handle: + marker = RUN_RE.search(line) + if marker: + run = {"time": marker.group(1), "minutes_now": int(marker.group(2)), "filtered": None, "force": None, "in_force": None, "in_force_charge": None} + runs.append(run) + continue + if run is None or run.get("comparing"): + continue + if COMPARE_RE.search(line): + run["comparing"] = True + continue + # A recomputing run prints the re-plan's fresh window list before any plan in force, so has none to read + if RECOMPUTE_RE.search(line): + run["recompute"] = True + continue + # A run that finds the plan invalid (the previous run's adoption was overridden, as when the 8-hourly + # config refresh is pending) adopts its re-plan without comparing it to the old plan + if INVALID_RE.search(line): + run["invalid"] = True + continue + # The first "Best export window" of a run is the plan in force when it starts - the one the previous + # run adopted. Later ones in the same run are the re-plan's working lists. + if run["in_force"] is None and run["in_force_charge"] is None and not run.get("recompute"): + found = IN_FORCE_CHARGE_RE.search(line) + if found: + run["in_force_charge"] = found.group(1) + continue + if run["in_force"] is None and not run.get("recompute"): + found = IN_FORCE_RE.search(line) + if found: + run["in_force"] = found.group(1) + continue + if parse_human_car_lines(run, line): + continue + if REPLAN_RE.search(line): + run["replan"] = True + continue + found = SOC_EACH_RE.search(line) + if found: + # The first line per inverter is the SoC the plan starts from; each is logged again after executing + run.setdefault("soc_each", {}).setdefault(int(found.group(1)), float(found.group(2))) + found = SOC_TOTAL_RE.search(line) + if found and not run.get("soc_total"): + run["soc_total"] = (float(found.group(1)), float(found.group(2))) + continue + for regex, store in ( + (SOC_RE, "soc"), + (TODAY_RE, "today"), + (INDAY_RE, "inday"), + (DIVERGENCE_RE, "divergence"), + (DIVERGENCE_EXACT_RE, "divergence_exact"), + (COST_RE, "cost"), + (NEXT_LIMIT_RE, "next_limit"), + (VERSION_RE, "version"), + (LOAD_INPUT_RE, "load_input"), + (LOAD_EXACT_RE, "load_exact"), + (LOAD_COMPACT_RE, "load_exact"), + (PV_INPUT_RE, "pv_input"), + (PV_EXACT_RE, "pv_exact"), + (STATE_INPUT_RE, "state"), + (RATES_INPUT_RE, "rates"), + (CARS_INPUT_RE, "cars"), + (INVERTER_INPUT_RE, "inverter"), + (FILTERED_RE, "filtered"), + (FORCE_RE, "force"), + ): + # A run logs the inverter's SoC again after executing the plan; the plan started from the first + if store == "soc" and run.get("soc"): + continue + found = regex.search(line) + if found: + if store == "state": + run[store] = parse_state(found.group(1)) + elif store == "rates": + run[store] = parse_rates(found.groups()) + elif store in ("cars", "inverter"): + run[store] = ast.literal_eval(found.group(1)) + else: + run[store] = found.groups() if store in ("soc", "today", "force", "next_limit", "load_input", "load_exact", "pv_input", "pv_exact") else found.group(1) + kept = [] + pending = {} + for run in runs: + # Rates, cars and dispatches are logged only when they change, so a change logged by a dropped run still holds for the runs after it + for store in ("rates", "cars", "inverter", "octopus_slots"): + pending[store] = run.get(store) or pending.get(store) + if run.get("soc"): + for store in ("rates", "cars", "inverter", "octopus_slots"): + if pending.get(store) and not run.get(store): + run[store] = pending[store] + pending = {} + kept.append(run) + return kept + + +# The parsed "Replay input:" lines; a log with none of them comes from Predbat before they were added +REPLAY_INPUT_STORES = ("state", "rates", "cars", "inverter", "load_exact", "load_input", "pv_exact", "pv_input", "divergence_exact") + + +def parse_human_car_lines(run, line): + """Read the human-readable car and dispatch lines older logs carry into run, returning True if line was one. + + Formats have changed over the years, so anything that does not read back is skipped rather than raised. + """ + found = CAR_PLAN_RE.search(line) + if found: + plans = run.setdefault("car_plans", {}) + # The first plan in a run is the one fetch built and the plan reads; later ones are re-logs + if int(found.group(1)) not in plans: + try: + plans[int(found.group(1))] = ast.literal_eval(found.group(2)) + except (ValueError, SyntaxError): + pass + return True + found = CAR_FLAGS_RE.search(line) + if found: + if "car_flags" not in run: + try: + run["car_flags"] = (ast.literal_eval(found.group(1)), ast.literal_eval(found.group(2))) + except (ValueError, SyntaxError): + pass + return True + found = OCTOPUS_SLOTS_RE.search(line) + if found: + # "from to ": both read back, so split at the " to " that leaves two valid literals + text = found.group(1) + index = text.find("] to [") + while index >= 0: + try: + ast.literal_eval(text[: index + 1]) + run["octopus_slots"] = ast.literal_eval(text[index + 5 :]) + break + except (ValueError, SyntaxError): + index = text.find("] to [", index + 1) + return True + return False + + +def apply_human_car_lines(my_predbat, run): + """Set the car state from an older log's human-readable lines, where the run has no exact cars line.""" + if run.get("cars"): + return + for car_n, slots in (run.get("car_plans") or {}).items(): + if car_n < len(my_predbat.car_charging_slots or []): + my_predbat.car_charging_slots[car_n] = slots + if run.get("car_flags"): + planned, now = run["car_flags"] + if len(planned) == my_predbat.num_cars: + my_predbat.car_charging_planned = planned + if len(now) == my_predbat.num_cars: + my_predbat.car_charging_now = now + + +def rebuild_io_rates(my_predbat): + """Rebuild the import rates from the logged dispatch list, as fetch does, for a log that has no rates lines. + + Starts from the rates before any dispatch (rate_import_no_io, from the yaml) and adds each car's dispatches, then + the saving and free sessions, with the live code. Rate overrides and manual rates are not reapplied. + """ + my_predbat.io_adjusted = {} + rates = dict(my_predbat.rate_import_no_io or {}) + if not rates: + return + for car_n in range(my_predbat.num_cars): + if car_n < len(my_predbat.octopus_slots or []): + rates = my_predbat.rate_add_io_slots(car_n, rates, my_predbat.octopus_slots[car_n]) + my_predbat.load_saving_slot(my_predbat.octopus_saving_slots, rates, export=False, rate_replicate=my_predbat.rate_import_replicated) + my_predbat.load_free_slot(my_predbat.octopus_free_slots, rates, export=False, rate_replicate=my_predbat.rate_import_replicated) + my_predbat.rate_import = rates + + +def parse_state(text): + """Parse the name value pairs of a "Replay input: state" line into a dict of floats, None where the log had none.""" + tokens = text.split() + return {name: None if value == "None" else float(value) for name, value in zip(tokens[::2], tokens[1::2])} + + +def parse_rates(groups): + """Parse a "Replay input: rates changed" line into (start minute, {series: (change points, end)}). + + Each series is a list of [minutes from start, rate] at every change of rate, followed by the minute from start it + runs to. + """ + hours, minutes, text = groups + series = {} + for name, points, end in RATES_SERIES_RE.findall(text): + series[name] = ([(int(offset), float(rate)) for offset, rate in ast.literal_eval(points)], int(end)) + return int(hours) * 60 + int(minutes), series + + +def today_values(run): + """Return a run's four day counters (load, import, export, PV), exact from its state line when it has one, else None.""" + state = run.get("state") + if state and all(state.get(name) is not None for name in ("load_today", "import_today", "export_today", "pv_today")): + return (state["load_today"], state["import_today"], state["export_today"], state["pv_today"]) + return run.get("today") + + +def shift_counter(history, minutes, delta): + """Advance a backwards cumulative history by minutes, adding delta kWh over the gap. + + The history is indexed by minutes ago, with index 0 the latest counter and larger indexes older (smaller) + values, so advancing time moves every existing entry to a higher index and the gap fills with a ramp from + the old latest value up to the new one. The growth is spread evenly across the gap, which is all the log's + once-per-run counters can tell us. + """ + if minutes <= 0 or not history: + return history + old_latest = history.get(0, 0.0) + if isinstance(history, dict): + # A plain dict history may be sparse, so shift its keys rather than assuming a dense range + result = {key + minutes: value for key, value in history.items()} + for key in range(minutes): + result[key] = old_latest + delta * (minutes - key) / minutes + return result + shifted = array.array("d", [0.0]) * (len(history) + minutes) + for key in range(minutes): + shifted[key] = old_latest + delta * (minutes - key) / minutes + for key in range(len(history)): + shifted[key + minutes] = history.get(key, 0.0) + result = MinuteArray({}, 0) + result._data = shifted # pylint: disable=protected-access + return result + + +def set_export_window(my_predbat, force, now_minutes, limit=None): + """Set the inverter's programmed export window and its limit from the log, or clear them. + + force is the log's force export line; limit is the (mode, target, power) the log gave for the next export + window. The window and its limit must stay the same length, as the base prediction reads them together. + """ + if force and force[0] == "True": + start = int(force[1]) * 60 + int(force[2]) + end = int(force[3]) * 60 + int(force[4]) + # A window ending before it starts runs over midnight; seen from the small hours, it started yesterday + if end <= start: + end += 24 * 60 + if now_minutes < start - 12 * 60: + start -= 24 * 60 + end -= 24 * 60 + average = my_predbat.rate_export.get(start, 0) if my_predbat.rate_export else 0 + my_predbat.export_window = [{"start": start, "end": end, "average": average}] + if limit: + mode, target, power = limit + my_predbat.export_limits = [pack_export_limit(int(mode), None if target == "None" else int(target), float(power))] + else: + my_predbat.export_limits = [pack_export_limit(EXPORT_MODE_TARGET, 0)] + my_predbat.isExporting = start <= now_minutes < end + else: + my_predbat.export_window = [] + my_predbat.export_limits = [] + my_predbat.isExporting = False + + +def simulate_soc(my_predbat, soc_kw, minutes, pv_kwh, load_kwh): + """Advance the battery by minutes from soc_kw under the plan in force, with the PV and load that actually happened. + + The battery and inverter are modelled by Predbat's own prediction engine, so charge/discharge rate curves, + losses, reserve, the inverter AC limit (shared by PV and battery on a hybrid) and the export limit all apply + exactly as the planner sees them. The plan's forecast for the gap is replaced by the actual PV and load, + spread evenly over it. Must be called with the instance's clock still at the start of the gap and its + stepped PV and load models built for that moment (rebuild_load_pv_models), which supply the rest of the horizon. + """ + if minutes <= 0: + return soc_kw + pv_step = dict(my_predbat.pv_forecast_minute_step) + load_step = dict(my_predbat.load_minutes_step) + steps = max(minutes // PREDICT_STEP, 1) + for index in range(steps): + pv_step[index * PREDICT_STEP] = pv_kwh / steps + load_step[index * PREDICT_STEP] = load_kwh / steps + # The step just past the gap is simulated too, so it needs a value even where the model has none + pv_step.setdefault(steps * PREDICT_STEP, 0.0) + load_step.setdefault(steps * PREDICT_STEP, 0.0) + prediction = Prediction(my_predbat, pv_step, pv_step, load_step, load_step, soc_kw=soc_kw) + # Only the gap is needed, so stop the simulation just after it rather than running the whole horizon + prediction.forecast_minutes = (steps + 1) * PREDICT_STEP + prediction.run_prediction(my_predbat.charge_limit_best, my_predbat.charge_window_best, my_predbat.export_window_best, my_predbat.export_limits_best, False, end_record=prediction.forecast_minutes, save="replay") + return prediction.predict_soc.get(steps * PREDICT_STEP, soc_kw) + + +def counter_gain(now_value, prev_value, new_day=False): + """Return the kWh a day counter gained between two runs. + + The counters restart at midnight, so across one the reading itself is the gain since midnight; what came in + between the last run before midnight and midnight itself is lost - at most one run's worth. Within a day a + reading below the previous one is sensor noise, and counts as no gain. + """ + now_value, prev_value = float(now_value), float(prev_value) + if new_day: + return now_value + return max(now_value - prev_value, 0.0) + + +def crosses_midnight(prev, run): + """Return True if run is on a later day than prev, the run (or the yaml's moment) before it.""" + return run["time"][:10] != prev["time"][:10] + + +def shift_cumulative(data, minutes): + """Move a cumulative-from-midnight series back by minutes, so it counts from the later midnight instead.""" + base = 0.0 + for minute in sorted(data): + if minute > minutes: + break + base = data[minute] + return {minute - minutes: value - base for minute, value in data.items()} + + +def shift_windows(windows, minutes): + """Move each window's minutes back by minutes, returning new windows and leaving the originals alone.""" + shifted = [] + for window in windows: + window = dict(window) + for key in WINDOW_MINUTE_KEYS: + if isinstance(window.get(key), int): + window[key] -= minutes + shifted.append(window) + return shifted + + +def roll_over_midnight(my_predbat, days=1): + """Move the instance into a later day: everything held as minutes from midnight moves back a day per day. + + The clock (now_utc) is left where it is and minutes_now goes negative, so apply_run then advances it across + midnight in the new day's minutes. Predbat counts wall-clock minutes from midnight, so a day is always 1440 + minutes, even when the clocks change. + + Only what the yaml carried moves; nothing new arrives. Rates the live system fetched since - the next day-ahead + prices, say - come from the log's rates lines (apply_logged_rates); without them the plan sees the yaml's rates + running out a day sooner. + """ + minutes = days * 24 * 60 + for name in DAY_KEYED_DICTS: + data = getattr(my_predbat, name, None) + if data: + setattr(my_predbat, name, {key - minutes: value for key, value in data.items()}) + if my_predbat.load_forecast: + my_predbat.load_forecast = shift_cumulative(my_predbat.load_forecast, minutes) + my_predbat.load_forecast_array = [shift_cumulative(forecast, minutes) for forecast in (my_predbat.load_forecast_array or [])] + for name in DAY_WINDOW_LISTS: + windows = getattr(my_predbat, name, None) + if windows: + setattr(my_predbat, name, shift_windows(windows, minutes)) + my_predbat.car_charging_slots = [shift_windows(slots, minutes) for slots in (my_predbat.car_charging_slots or [])] + for name in DAY_MINUTE_LISTS: + values = getattr(my_predbat, name, None) + if values: + setattr(my_predbat, name, [value - minutes for value in values]) + my_predbat.midnight_utc = my_predbat.midnight_utc + timedelta(days=days) + my_predbat.minutes_now -= minutes + + +def run_soc(run, soc_max=None): + """The battery's SoC (kWh) and percentage at a run, across all inverters. + + From the totals line where an older log has one, else the sum of each inverter's own SoC line (as a percentage of + soc_max, the system's capacity), else inverter 0's line for a single inverter. + """ + if run.get("soc_total"): + total_max, soc_kw = run["soc_total"] + return soc_kw, int(round(soc_kw / total_max * 100)) if total_max else 0 + each = run.get("soc_each") or {} + if len(each) > 1 and soc_max: + soc_kw = sum(each.values()) + return soc_kw, int(round(soc_kw / soc_max * 100)) + return float(run["soc"][0]), int(run["soc"][1]) + + +def apply_run(my_predbat, prev, run): + """Move the restored instance forwards from the previous run's moment to this run's.""" + gap = run["minutes_now"] - my_predbat.minutes_now + if gap < 0: + raise ValueError("Log run at minute {} is before the state at minute {}".format(run["minutes_now"], my_predbat.minutes_now)) + now_today, prev_today = today_values(run), today_values(prev) + if now_today and prev_today: + for name, now_value, prev_value in zip(COUNTER_ARRAYS, now_today, prev_today): + setattr(my_predbat, name, shift_counter(getattr(my_predbat, name), gap, counter_gain(now_value, prev_value, crosses_midnight(prev, run)))) + elif gap: + for name in COUNTER_ARRAYS: + setattr(my_predbat, name, shift_counter(getattr(my_predbat, name), gap, 0.0)) + for name in AGED_ARRAYS: + history = getattr(my_predbat, name, None) + if isinstance(history, list): + # One history per car + setattr(my_predbat, name, [shift_counter(car, gap, 0.0) for car in history]) + elif history: + setattr(my_predbat, name, shift_counter(history, gap, 0.0)) + my_predbat.minutes_now = run["minutes_now"] + my_predbat.now_utc = my_predbat.now_utc + timedelta(minutes=gap) + my_predbat.now_utc_real = my_predbat.now_utc + soc_kw, soc_percent = run_soc(run, my_predbat.soc_max) + my_predbat.soc_kw = soc_kw + my_predbat.soc_percent = soc_percent + # One inverter takes it all; with several, each takes its own logged SoC, or a share of the total by capacity + each = run.get("soc_each") or {} + total_max = sum(inverter.soc_max for inverter in my_predbat.inverters) if len(my_predbat.inverters) > 1 else 0 + for index, inverter in enumerate(my_predbat.inverters): + if total_max and index in each: + inverter.soc_kw = each[index] + else: + inverter.soc_kw = soc_kw * inverter.soc_max / total_max if total_max else soc_kw + inverter.soc_percent = int(round(inverter.soc_kw / inverter.soc_max * 100)) if total_max else soc_percent + # Every prediction's metric starts from the cost so far today, and the prediction's day totals start from + # these counters; the live system recomputes both each run, so take them from the log too + if run.get("cost"): + my_predbat.cost_today_sofar = float(run["cost"]) + if now_today: + my_predbat.load_minutes_now, my_predbat.import_today_now, my_predbat.export_today_now, my_predbat.pv_today_now = (float(value) for value in now_today) + if run.get("rates"): + apply_logged_rates(my_predbat, run["rates"]) + for name, value in (run.get("cars") or {}).items(): + setattr(my_predbat, name, value) + apply_human_car_lines(my_predbat, run) + if run.get("pv_exact"): + apply_logged_pv_exact(my_predbat, run["pv_exact"]) + elif run.get("pv_input"): + apply_logged_pv_forecast(my_predbat, run["pv_input"]) + # Fetch clears these every run, so the plan's stale-p90 guard only ever compares within one cycle. Left set, + # a PV update that moves p50 but not p90 reads as a p90 left behind, and the plan replaces p90 with p50 + my_predbat.pv_forecast_minute90_signatures = None + if run.get("inday"): + my_predbat.load_inday_adjustment = float(run["inday"]) / 100.0 + # calculate_plan recomputes the load divergence from the load history, which the replay can only rebuild + # at the log's 5-minute resolution - smoother than the live 1-minute history, so it comes out different. + # Use the logged value instead; it is rounded to 2 dp of the fraction exactly as get_load_divergence returns it. + if run.get("divergence_exact"): + # None when the live plan had divergence off, which the rounded percentage line does not show + my_predbat.replay_load_divergence = None if run["divergence_exact"] == "None" else float(run["divergence_exact"]) + elif run.get("divergence"): + my_predbat.replay_load_divergence = round(float(run["divergence"]) / 100.0, 2) + apply_logged_state(my_predbat, run.get("state")) + # The window the inverter is holding is the one the previous run programmed; a log that records the inverter's + # state exactly supersedes this reconstruction from the previous run's lines + if getattr(my_predbat, "replay_inverter_logged", False): + # Logged only on a change, so between changes the state stays as the yaml or the last line left it + apply_logged_inverter(my_predbat, run.get("inverter")) + else: + set_export_window(my_predbat, prev.get("force"), my_predbat.minutes_now, prev.get("next_limit")) + + +def model_car_charging_now(my_predbat): + """Model a car charging now outside its plan, as dynamic_load() does every live cycle. + + The live plan holds the battery for such a car (car_charging_now_slots, read through car_charging_slots_model), + so without this a replay plans a battery charge the live run did not. Derived by the live code itself from the + car state, which the log carries. + """ + my_predbat.car_charging_now_slots = [[] for _car_n in range(my_predbat.num_cars)] + minutes_end_slot = int((my_predbat.minutes_now + my_predbat.plan_interval_minutes) / my_predbat.plan_interval_minutes) * my_predbat.plan_interval_minutes + my_predbat.dynamic_load_car_charging_now(minutes_end_slot) + + +def replay_forward(my_predbat, debug_file, log_file, until=None, quiet=False, simulate=False, overrides=None): + """Restore debug_file, then step through log_file re-planning where the log did; return the comparison rows. + + Each row is a dict with the run's time, whether it re-planned, the logged and replayed export windows, the + actual SoC from the log and, when simulate is set, the replay's own SoC. until is an optional HH:MM after + which the replay stops. + + With simulate the replay is closed-loop: the battery is stepped forward under the replayed plan using the + actual PV and load (see simulate_soc), and that SoC - not the logged one - is what each re-plan starts from. + Without it every re-plan starts from the SoC the log recorded. + + overrides maps instance attribute names to values set after the yaml is restored, for what-if replays such as + a different pv_metric90_weight (--override). + """ + restore_debug_state(my_predbat, debug_file) + apply_overrides(my_predbat, overrides) + my_predbat.plan_valid = True + rebuild_load_pv_models(my_predbat) + + # Every run is placed in minutes from the yaml day's midnight, so runs on later days follow on from it + start_date = my_predbat.now_utc.date() + plan_day = my_predbat.now_utc.strftime("%d-%m") + start = my_predbat.minutes_now + runs = [] + for run in parse_log(log_file): + run["minute"] = (date.fromisoformat(run["time"][:10]) - start_date).days * 24 * 60 + run["minutes_now"] + if run["minute"] > start: + runs.append(run) + until_minutes = None + if until: + until_minutes = int(until.split(":")[0]) * 60 + int(until.split(":")[1]) + # A time no later than the yaml's means that time the next day + if until_minutes <= start: + until_minutes += 24 * 60 + # The yaml's own day counters stand in for the run before the first one + yaml_today = (my_predbat.load_minutes_now, my_predbat.import_today_now, my_predbat.export_today_now, my_predbat.pv_today_now) + install_logged_load_divergence(my_predbat) + if not runs: + raise ValueError("No runs after the yaml's time in {} that this replay can read (a run needs a 'PredBat - update at' line and an inverter SoC line)".format(log_file)) + # A log that records the inverter's state replaces the reconstruction of it from other lines + my_predbat.replay_inverter_logged = any(run.get("inverter") for run in runs) + # A log with rates lines has the dispatch-adjusted rates already; an older one has them rebuilt from its dispatch list + my_predbat.replay_rates_logged = any(run.get("rates") for run in runs) + if not quiet and not any(run.get(store) for run in runs for store in REPLAY_INPUT_STORES): + print("Replay note: this log has no 'Replay input:' lines (Predbat before they were added), so the forecasts come from the yaml and the car, dispatches and other state from the human-readable lines. Expect approximate plans, not a match.") + try: + rows = replay_runs(my_predbat, runs, until_minutes, plan_day, yaml_today, simulate, quiet) + finally: + remove_logged_load_divergence(my_predbat) + my_predbat.__dict__.pop("replay_inverter_logged", None) + my_predbat.__dict__.pop("replay_rates_logged", None) + return rows + + +def install_logged_load_divergence(my_predbat): + """Make get_load_divergence return the value the log recorded for the current run, when there is one.""" + original = my_predbat.get_load_divergence + + def logged_load_divergence(minutes_now, load_minutes): + """Return the logged divergence, falling back to computing it when the log had none.""" + value = getattr(my_predbat, "replay_load_divergence", None) + if value is None: + return original(minutes_now, load_minutes) + return value if my_predbat.metric_load_divergence_enable else None + + my_predbat.get_load_divergence = logged_load_divergence + my_predbat.replay_load_divergence = None + + +def remove_logged_load_divergence(my_predbat): + """Undo install_logged_load_divergence, so the shared instance is left as it was found.""" + for name in ("get_load_divergence", "replay_load_divergence"): + if name in my_predbat.__dict__: + del my_predbat.__dict__[name] + + +def parse_override(text): + """Parse a name=value override, reading the value as a number or boolean when it looks like one.""" + name, _, value = text.partition("=") + if not name or not _: + raise ValueError("Expected name=value, got {}".format(text)) + lowered = value.strip().lower() + if lowered in ("true", "false"): + return name.strip(), lowered == "true" + try: + return name.strip(), int(value) + except ValueError: + pass + try: + return name.strip(), float(value) + except ValueError: + return name.strip(), value + + +def version_change(runs): + """Return (index, old version, new version) for the first run whose logged version differs, or None.""" + version = None + for index, run in enumerate(runs): + if not run.get("version"): + continue + if version is None: + version = run["version"] + elif run["version"] != version: + return index, version, run["version"] + return None + + +def replay_runs(my_predbat, runs, until_minutes, plan_day, yaml_today, simulate, quiet): + """Step through the runs, re-planning where the log did, and return the comparison rows.""" + sim_soc = my_predbat.soc_kw + # The yaml's own moment stands in for the run before the first one + prev = {"today": None, "force": None, "time": my_predbat.now_utc.isoformat(sep=" ")} + rows = [] + # A faithful replay needs the code that wrote the log, so past a version change it can only be expected to + # match loosely. Carry on, but mark every row from the change onwards so results can be judged separately. + change = version_change(runs) + change_index = None + if change is not None: + change_index, before, after = change + print("Replay note: the log changes from Predbat {} to {} at {}; plans after that are not expected to match as closely".format(before, after, runs[change_index]["time"][11:16])) + # Minutes from the yaml day's midnight to the instance's own midnight + day_start = 0 + for index, run in enumerate(runs): + if until_minutes is not None and run["minute"] > until_minutes: + break + next_run = runs[index + 1] if index + 1 < len(runs) else None + if run["minute"] - day_start >= 24 * 60: + days = (run["minute"] - day_start) // (24 * 60) + roll_over_midnight(my_predbat, days) + day_start += days * 24 * 60 + if not quiet: + print("Replay: rolled over midnight into {}".format(run["time"][:10])) + if simulate: + before = today_values(prev) or yaml_today + now_today = today_values(run) or before + new_day = crosses_midnight(prev, run) + load_kwh = counter_gain(now_today[0], before[0], new_day) + pv_kwh = counter_gain(now_today[3], before[3], new_day) + rebuild_load_pv_models(my_predbat) + sim_soc = simulate_soc(my_predbat, sim_soc, run["minutes_now"] - my_predbat.minutes_now, pv_kwh, load_kwh) + apply_run(my_predbat, prev, run) + if run.get("octopus_slots") is not None and not my_predbat.replay_rates_logged: + my_predbat.octopus_slots = run["octopus_slots"] + rebuild_io_rates(my_predbat) + model_car_charging_now(my_predbat) + # Live rebuilds the load forecast every run, re-plan or not, so the instance holds what live held at each run + refresh_load_forecast(my_predbat, run) + if simulate: + my_predbat.soc_kw = sim_soc + my_predbat.soc_percent = int(round(sim_soc / my_predbat.soc_max * 100)) if my_predbat.soc_max else 0 + for inverter in my_predbat.inverters: + inverter.soc_kw = sim_soc + inverter.soc_percent = my_predbat.soc_percent + row = { + "time": run["time"][11:16], + # From the yaml day's midnight, like the windows below, so rows after midnight carry on from it + "minutes_now": run["minute"], + "soc_percent": run_soc(run, my_predbat.soc_max)[1], + "soc_sim_percent": my_predbat.soc_percent if simulate else None, + "replanned": run["filtered"] is not None or bool(run.get("replan")), + "logged": None, + "replayed": None, + "logged_charge": None, + "replayed_charge": None, + # The plan's car slots and the reserve, for the plan timeline (minutes from the yaml day's midnight) + "car_slots": car_slots_now(my_predbat, run["minute"] - run["minutes_now"]), + "reserve_percent": my_predbat.reserve_percent, + "logged_candidate": parse_windows(run["filtered"], plan_day) if run["filtered"] else None, + "replayed_candidate": None, + "after_version_change": change_index is not None and index >= change_index, + } + # Marks the replay's own log the way the live log marks each run, so the two can be read side by side + my_predbat.log("--------------- Replay of run at {} minutes now {}".format(run["time"], my_predbat.minutes_now)) + if row["replanned"]: + # Candidate windows start at the current slot, so they move with the clock as fetch moves them + rescan_rate_stats(my_predbat) + rescan_rate_windows(my_predbat) + rebuild_load_pv_models(my_predbat) + pv_step = my_predbat.pv_forecast_minute_step + load_step = my_predbat.load_minutes_step + my_predbat.prediction = Prediction(my_predbat, pv_step, pv_step, load_step, load_step) + if run.get("invalid"): + # The live run found its plan invalid, so it adopted the new plan without comparing it to the old + my_predbat.plan_valid = False + candidate = capture_candidate(my_predbat) + row["replayed_candidate"] = parse_windows(candidate, plan_day) if candidate else None + adopted = parse_windows(my_predbat.window_as_text(my_predbat.export_window_best, my_predbat.export_limits_best), plan_day) + # The log shows the adopted plan at the start of the next run, with windows that ended by then dropped + if next_run and next_run["in_force"] is not None: + row["logged"] = parse_windows(next_run["in_force"], plan_day) + row["replayed"] = [window for window in adopted if window[1] > next_run["minute"]] + if next_run.get("in_force_charge") is not None: + adopted_charge = parse_windows(my_predbat.window_as_text(my_predbat.charge_window_best, calc_percent_limit(my_predbat.charge_limit_best, my_predbat.soc_max)), plan_day) + row["logged_charge"] = parse_windows(next_run["in_force_charge"], plan_day) + row["replayed_charge"] = [window for window in adopted_charge if window[1] > next_run["minute"]] + rows.append(row) + prev = run + if not quiet and row["replanned"]: + print(format_row(row)) + return rows + + +def rescan_rate_stats(my_predbat): + """Recompute the rate min/max/average and the forward-looking rate curves for the current time, as fetch does every run. + + They are taken over the horizon from now, so they move as the clock does: a peak that has passed drops out + of rate_max, which changes the charge/export thresholds and the battery value. The rates themselves are + the final ones the yaml holds, which is what fetch's last scan reads too. + """ + if my_predbat.rate_import: + my_predbat.rate_scan(my_predbat.rate_import, print=True) + if my_predbat.rate_import_base: + my_predbat.rate_min_base, my_predbat.rate_max_base, _, _, _ = my_predbat.rate_minmax(my_predbat.rate_import_base) + if my_predbat.rate_export: + my_predbat.rate_scan_export(my_predbat.rate_export, print=False) + if my_predbat.rate_export_base: + my_predbat.rate_export_max_forward = my_predbat.rate_export_max_forward_calc(my_predbat.rate_export_base) + + +def refresh_load_forecast(my_predbat, run): + """Bring the load forecast up to this run: from the log's load line where it has one, else rebuilt from history.""" + rebuild_load_forecast(my_predbat) + if run.get("load_exact"): + # A log that records the load forecast exactly as the plan reads it makes the rebuild unnecessary + apply_logged_load_exact(my_predbat, run["load_exact"]) + elif run.get("load_input"): + # Older logs give it per 5-minute slot, rounded + apply_logged_load_forecast(my_predbat, run["load_input"]) + + +def rebuild_load_forecast(my_predbat): + """Rebuild the weighted-bucket historical load forecast for the current time, as fetch does every run. + + Only for installs using it (days_previous_auto) and no other load forecast source, which is the case the + replay supports so far: the forecast is then this alone. Without it every re-plan keeps the yaml's forecast. + """ + if not my_predbat.load_forecast_history or my_predbat.load_minutes_age < 1: + return + forecast = my_predbat.compute_load_forecast_history(my_predbat.now_utc) + if forecast: + my_predbat.load_forecast = dict(forecast) + + +def parse_values(text): + """Parse a logged comma-separated list of numbers, empty when the list was.""" + return [float(value) for value in text.split(",") if value.strip()] + + +def apply_logged_load_forecast(my_predbat, load_input): + """Replace the load forecast from the run's logged "Replay input: load forecast" line. + + The log gives Wh per 5 minutes from a slot start; load_forecast is cumulative kWh from midnight, so the + logged slots are stacked onto the forecast's own value at that start, spread evenly within each slot. + Minutes before the start keep their values, as the plan only reads them for the in-day comparison. + """ + hours, minutes, text = load_input + start = int(hours) * 60 + int(minutes) + forecast = my_predbat.load_forecast or {} + base = 0.0 + for minute in sorted(forecast): + if minute > start: + break + base = forecast[minute] + rebuilt = {minute: value for minute, value in forecast.items() if minute < start} + total = base + for index, wh in enumerate(parse_values(text)): + kwh = wh / 1000.0 + for offset in range(PREDICT_STEP): + rebuilt[start + index * PREDICT_STEP + offset] = total + kwh * offset / PREDICT_STEP + total += kwh + rebuilt[start + len(parse_values(text)) * PREDICT_STEP] = total + my_predbat.load_forecast = rebuilt + + +def expand_compact_load(base, text): + """Rebuild the [step start, minute after] cumulative kWh pairs from a compact "Replay input: load from" line. + + Every value is counted in whole tenths of a Wh and divided by 10000 only at the end, which gives exactly the + dp4 float the live forecast held. + """ + tenths = round(float(base) * 10) + pairs = [] + for part in text.split(", "): + step, first = (round(float(value) * 10) for value in part.split("/")) + pairs.append([tenths / 10000, (tenths + first) / 10000]) + tenths += step + return pairs + + +def apply_logged_load_exact(my_predbat, load_exact): + """Set the load forecast from the run's logged load forecast line, compact ("load from") or full ("load forecast, cumulative kWh"). + + The line gives, for each 5-minute step from the logged start, load_forecast at the step's start and the minute + after - the two values step_data_history() reads - so those are set exactly, and removed where the log gave + None. Other minutes keep their values; the plan does not read them. + """ + if len(load_exact) == 4: + hours, minutes, base, text = load_exact + pairs = expand_compact_load(base, text) + else: + hours, minutes, text = load_exact + pairs = ast.literal_eval(text) + start = int(hours) * 60 + int(minutes) + forecast = dict(my_predbat.load_forecast or {}) + for index, values in enumerate(pairs): + for offset, value in enumerate(values): + minute = start + index * PREDICT_STEP + offset + if value is None: + forecast.pop(minute, None) + else: + forecast[minute] = float(value) + my_predbat.load_forecast = forecast + + +def apply_logged_pv_forecast(my_predbat, pv_input): + """Update the PV forecasts from a logged "Replay input: PV forecast changed" line. + + Each series is logged as kWh per half hour from a half-hour start, which is spread evenly over the minutes of + its half hour. Minutes outside the logged span keep their values; a series logged empty is left alone. + """ + hours, minutes = pv_input[0], pv_input[1] + start = int(hours) * 60 + int(minutes) + for name, text in zip(("pv_forecast_minute", "pv_forecast_minute10", "pv_forecast_minute90"), pv_input[2:]): + values = parse_values(text) + if not values: + continue + series = dict(getattr(my_predbat, name) or {}) + for index, kwh in enumerate(values): + for offset in range(30): + series[start + index * 30 + offset] = kwh / 30.0 + setattr(my_predbat, name, series) + + +def apply_logged_inverter(my_predbat, inverter): + """Set the inverter's programmed state from a run's "Replay input: inverter changed" line, when it has one.""" + for name, value in (inverter or {}).items(): + setattr(my_predbat, name, value) + + +def apply_logged_state(my_predbat, state): + """Set the plan's starting values from a run's "Replay input: state" line, which the other lines round. + + The day counters are taken through today_values; a value the log gave as None is left alone. + """ + if not state: + return + if state.get("soc_kw") is not None: + my_predbat.soc_kw = state["soc_kw"] + for inverter in my_predbat.inverters: + inverter.soc_kw = state["soc_kw"] + if state.get("soc_max") is not None: + my_predbat.soc_max = state["soc_max"] + if state.get("inday") is not None: + my_predbat.load_inday_adjustment = state["inday"] + if state.get("cost_today") is not None: + my_predbat.cost_today_sofar = state["cost_today"] + # The rates the inverter is running at now, which the prediction starts from (Predbat may have throttled them) + for name in ("charge_rate_now", "discharge_rate_now"): + if state.get(name) is not None: + setattr(my_predbat, name, state[name]) + # Moved here from the inverter line so a one-degree change does not re-log the whole inverter; an int live + if state.get("battery_temperature") is not None: + my_predbat.battery_temperature = int(state["battery_temperature"]) + + +def apply_logged_rates(my_predbat, rates_input): + """Replace the rates from a logged "Replay input: rates changed" line. + + Each series is rebuilt per minute from its change points over the span the log gave, and ends where the live + rates ended. Minutes before the logged start keep their values; only the cost so far reads them, and that comes + from the log. A line carried over from a run before midnight is in that day's minutes, so moves back a day. + """ + start, series = rates_input + if start > my_predbat.minutes_now: + start -= 24 * 60 + for name, (points, end) in series.items(): + attribute = RATES_ATTRIBUTES.get(name) + if attribute is None: + continue + rates = {minute: value for minute, value in (getattr(my_predbat, attribute, None) or {}).items() if minute < start} + for index, (offset, rate) in enumerate(points): + until = points[index + 1][0] if index + 1 < len(points) else end + for minute in range(start + offset, start + until): + rates[minute] = rate + setattr(my_predbat, attribute, rates) + + +def apply_logged_pv_exact(my_predbat, pv_exact): + """Set the PV forecasts from a logged "Replay input: PV forecast changed, per-minute kWh runs" line. + + Each series is given per minute from the logged start to the end of the plan as runs of [kWh, minutes], so the + minutes it covers are set exactly, and removed where the log gave None. Minutes outside it keep their values. + """ + hours, minutes = pv_exact[0], pv_exact[1] + start = int(hours) * 60 + int(minutes) + for name, text in zip(("pv_forecast_minute", "pv_forecast_minute10", "pv_forecast_minute90"), pv_exact[2:]): + series = dict(getattr(my_predbat, name) or {}) + minute = start + for value, count in ast.literal_eval(text): + for _ in range(count): + if value is None: + series.pop(minute, None) + else: + series[minute] = float(value) + minute += 1 + setattr(my_predbat, name, series) + + +def capture_candidate(my_predbat): + """Re-plan, returning the candidate plan's window text that calculate_plan logs before deciding whether to adopt it.""" + captured = [] + original = my_predbat.log + + def log(message, *args, **kwargs): + """Keep the candidate plan line, then log as normal.""" + found = FILTERED_RE.search(str(message)) + if found: + captured.append(found.group(1)) + return original(message, *args, **kwargs) + + my_predbat.log = log + try: + my_predbat.calculate_plan(recompute=True) + finally: + del my_predbat.log + return captured[-1] if captured else None + + +def first_window(windows): + """Return the first window as a short string, or '-' if there is none.""" + if not windows: + return "-" + return "{}-{} @{:g}%".format(minute_label(windows[0][0]), minute_label(windows[0][1]), windows[0][3]) + + +def format_row(row): + """Format one replanned row: time, logged first window, replayed first window and whether the lists match.""" + adopted = "same" if row["logged"] == row["replayed"] else "DIFF" + candidate = "same" if row.get("logged_candidate") == row.get("replayed_candidate") else "DIFF" + return "{} adopted: logged {:<26} replay {:<26} {} candidate {}".format(row["time"], first_window(row["logged"]), first_window(row["replayed"]), adopted, candidate) + + +def car_slots_now(my_predbat, offset): + """The first car's planned charging slots as (start, end) minutes from the yaml day's midnight.""" + slots = (my_predbat.car_charging_slots or [[]])[0] if my_predbat.num_cars else [] + return [(slot["start"] + offset, slot["end"] + offset) for slot in slots or []] + + +# The web plan's state for a slot, and its colour there (output.py), plus the car hold +PLAN_STATES = { + "Chrg": "#3AEE85", + "HoldChrg": "#34DBEB", + "FrzChrg": "#C8C8C8", + "Exp": "#FFD000", + "HoldExp": "#FFF09A", + "FrzExp": "#8C8C8C", + "Car": "#B48CE6", +} + + +def plan_state_now(charge_windows, export_windows, minutes_now, soc_percent, reserve_percent, car_slots): + """The plan's state at minutes_now, by the web plan's rules: an export instruction wins, then a charge + instruction, then a car slot (the battery is held while the car charges); None for plain demand. + + Window percents are as window_as_text logs them: an export window's target (99 = Freeze Export, 100 = + idle), a charge window's limit (0 = off, the reserve = Freeze Charge, at or below the SoC = hold). + """ + for start, end, _rate, percent in export_windows or []: + if start <= minutes_now < end and percent < 100: + if percent >= 99: + return "FrzExp" + return "HoldExp" if percent > soc_percent else "Exp" + for start, end, _rate, percent in charge_windows or []: + if start <= minutes_now < end and percent > 0: + if percent == reserve_percent: + return "FrzChrg" + return "HoldChrg" if percent <= soc_percent else "Chrg" + for start, end in car_slots or []: + if start <= minutes_now < end: + return "Car" + return None + + +def chart_replay(rows, filename, title="Replay"): + """Chart a replay as a PNG: actual SoC against each plan's export target, and a timeline of what each plan said. + + The live plan (from the log) and the replayed plan are each carried forward between re-plans, so every run + shows the plan in force at that moment. The target is the SoC the first forced-export window aims for, + on the same % scale as the SoC itself. The timeline gives each plan's state at each run in the web plan's + terms (charge, hold, freeze, export, car), and the car's planned charging. Uses the Agg backend so it never + opens a window. + """ + import matplotlib + + matplotlib.use("Agg") + import matplotlib.pyplot as plt + from matplotlib.patches import Patch + + colours = {"Live (log)": "#2a78d6", "Replay": "#eb6834"} + ink, muted, grid = "#0b0b0b", "#52514e", "#e6e5e1" + times = [row["minutes_now"] / 60.0 for row in rows] + # Each run's state lasts until the next run + widths = [later - now for now, later in zip(times, times[1:])] + [(times[1] - times[0]) if len(times) > 1 else 5 / 60.0] + + # Carry each plan forward from its last re-plan + carried = {name: (None, None) for name in colours} + states = {name: [] for name in colours} + targets = {name: [] for name in colours} + for row in rows: + if row["replanned"] and row["logged"] is not None: + carried["Live (log)"] = (row["logged"], row.get("logged_charge")) + carried["Replay"] = (row["replayed"], row.get("replayed_charge")) + for name in colours: + export_windows, charge_windows = carried[name] + soc = row["soc_percent"] + if name == "Replay" and row.get("soc_sim_percent") is not None: + soc = row["soc_sim_percent"] + states[name].append(plan_state_now(charge_windows, export_windows, row["minutes_now"], soc, row.get("reserve_percent"), row.get("car_slots"))) + forced = [window for window in export_windows or [] if window[3] < 99] + targets[name].append(forced[0][3] if forced else None) + + fig, (ax_soc, ax_mode) = plt.subplots(2, 1, figsize=(11, 7), sharex=True, gridspec_kw={"height_ratios": [3, 1.3]}) + fig.suptitle(title, color=ink, fontsize=13, x=0.06, ha="left") + + ax_soc.plot(times, [row["soc_percent"] for row in rows], color=ink, linewidth=2, label="Actual SoC (log)") + if any(row.get("soc_sim_percent") is not None for row in rows): + ax_soc.plot(times, [row.get("soc_sim_percent") for row in rows], color=colours["Replay"], linewidth=2, label="Replay simulated SoC") + for name, colour in colours.items(): + ax_soc.step(times, [float("nan") if value is None else value for value in targets[name]], where="post", color=colour, linewidth=2, linestyle="--", label="{} export target".format(name)) + ax_soc.set_ylabel("Battery SoC (%)", color=muted) + ax_soc.set_ylim(0, 105) + ax_soc.legend(frameon=False, loc="lower left") + + # One lane per plan, plus the car's planned charging (the same logged input for both) + lanes = [("Car slot", ["Car" if any(start <= row["minutes_now"] < end for start, end in row.get("car_slots") or []) else None for row in rows])] + lanes += [(name, states[name]) for name in reversed(list(colours))] + for lane, (_name, lane_states) in enumerate(lanes): + for hour, width, state in zip(times, widths, lane_states): + if state: + ax_mode.add_patch(plt.Rectangle((hour, lane + 0.15), width, 0.7, facecolor=PLAN_STATES[state], edgecolor="none")) + ax_mode.set_yticks([lane + 0.5 for lane in range(len(lanes))], [name for name, _states in lanes]) + ax_mode.set_ylim(0, len(lanes)) + ax_mode.set_ylabel("Plan says", color=muted) + ax_mode.set_xlabel("Time of day (hour)", color=muted) + # Hours count on from the yaml day's midnight, so a replay that crosses midnight wraps back to 0 + ax_mode.xaxis.set_major_formatter(matplotlib.ticker.FuncFormatter(lambda hour, _position: "{:g}".format(hour % 24))) + used = [state for state in PLAN_STATES if any(state in lane_states for _name, lane_states in lanes)] + ax_mode.legend(handles=[Patch(facecolor=PLAN_STATES[state], label=state) for state in used] + [Patch(facecolor="white", edgecolor=grid, label="Demand")], frameon=False, ncol=len(used) + 1, loc="upper center", bbox_to_anchor=(0.5, -0.32), fontsize=8) + + changes = [hour for row, hour in zip(rows, times) if row.get("after_version_change")] + if changes: + for axis in (ax_soc, ax_mode): + axis.axvline(changes[0], color=muted, linestyle=":", linewidth=1.5) + ax_soc.text(changes[0], 102, " version change", color=muted, fontsize=8, va="bottom") + for axis in (ax_soc, ax_mode): + axis.grid(True, color=grid, linewidth=0.8) + axis.set_axisbelow(True) + for side in ("top", "right"): + axis.spines[side].set_visible(False) + axis.tick_params(colors=muted) + fig.tight_layout() + fig.savefig(filename, dpi=110) + plt.close(fig) + + +def soc_rms_error(rows): + """Root-mean-square difference in SoC % between the replay's simulated battery and the log, or None when not simulating.""" + errors = [row["soc_sim_percent"] - row["soc_percent"] for row in rows if row.get("soc_sim_percent") is not None] + if not errors: + return None + return math.sqrt(sum(error * error for error in errors) / len(errors)) + + +def summarise(rows, logged="logged", replayed="replayed", after_version_change=False): + """Return (compared, identical, same_first_start) counts for a replay. + + By default this compares the adopted plans; pass logged="logged_candidate", replayed="replayed_candidate" to + compare the candidate plans each re-plan produced before deciding whether to adopt them. identical counts + re-plans whose whole export window list matches the log; same_first_start is the looser count where only the + first window's start agrees, which is the part that decides whether export is on now. Rows from a logged + version change onwards are counted only when after_version_change is set, as they are not expected to match. + """ + replanned = [row for row in rows if row["replanned"] and row.get(logged) is not None and row.get("after_version_change", False) == after_version_change] + identical = [row for row in replanned if row[logged] == row[replayed]] + same_start = [row for row in replanned if first_window(row[logged]).split("-")[0] == first_window(row[replayed]).split("-")[0]] + return len(replanned), len(identical), len(same_start) diff --git a/apps/predbat/tests/test_dummy_inverter.py b/apps/predbat/tests/test_dummy_inverter.py new file mode 100644 index 000000000..d34752d1a --- /dev/null +++ b/apps/predbat/tests/test_dummy_inverter.py @@ -0,0 +1,137 @@ +# fmt: off +# pylint: disable=line-too-long +"""Unit tests for the simulated inverter and battery (dummy_inverter.py).""" + +from config import INVERTER_DEF +from dummy_inverter import DUMMY_CAPABILITIES, DUMMY_DEFAULTS, DummyInverter, in_window, simulate_minute +from mock_base import MockBase + +IDLE = {"charge": {"enable": False}, "export": {"enable": False}, "reserve": 4} + + +def lossless(**overrides): + """Default parameters with no losses, so the arithmetic in a test is exact.""" + params = dict(DUMMY_DEFAULTS) + params.update({"battery_loss": 1.0, "battery_loss_discharge": 1.0, "inverter_loss": 1.0}) + params.update(overrides) + return params + + +def close(value, expected, tolerance=1e-6): + """True when value is within tolerance of expected.""" + return abs(value - expected) <= tolerance + + +def check(condition, message): + """Print message and return 1 when condition is false, else 0.""" + if not condition: + print("ERROR: " + message) + return 1 + return 0 + + +def test_eco(): + """Eco: surplus PV charges the battery, a shortfall is drawn from it, a full battery exports and then clips.""" + failed = 0 + soc, flows = simulate_minute(lossless(), IDLE, 5.0, 2.0, 0.5, 720) + failed += check(close(flows["battery"], -1.5) and close(flows["grid"], 0.0) and close(soc, 5.0 + 1.5 / 60), "surplus PV should charge the battery: {} {}".format(soc, flows)) + soc, flows = simulate_minute(lossless(), IDLE, 5.0, 0.0, 0.8, 0) + failed += check(close(flows["battery"], 0.8) and close(flows["grid"], 0.0), "the battery should cover the load: {}".format(flows)) + soc, flows = simulate_minute(lossless(), IDLE, 10.0, 7.0, 0.5, 720) + # The 5 kW inverter limit binds first: its AC output serves the 0.5 kW load, so only 4.5 kW reaches the grid + failed += check(close(flows["grid"], -4.5) and close(flows["clipped"], 2.0) and close(flows["pv"], 5.0), "a full battery should clip PV above the inverter limit: {}".format(flows)) + soc, flows = simulate_minute(lossless(export_limit=3000), IDLE, 10.0, 4.0, 0.5, 720) + failed += check(close(flows["grid"], -3.0) and close(flows["clipped"], 0.5), "PV above the export limit should clip: {}".format(flows)) + soc, flows = simulate_minute(lossless(), IDLE, 0.4, 0.0, 0.8, 0) + failed += check(close(flows["battery"], 0.0) and close(flows["grid"], 0.8), "the battery should not go below the reserve: {}".format(flows)) + return failed + + +def test_export_shares_the_inverter_limit(): + """During a forced export the battery only gets what PV leaves of the inverter's AC limit.""" + controls = {"charge": {"enable": False}, "export": {"enable": True, "start_time": "09:00:00", "end_time": "12:00:00", "target_soc": 20, "rate": 3600}, "reserve": 4} + failed = 0 + soc, flows = simulate_minute(lossless(), controls, 8.0, 1.0, 0.4, 600) + failed += check(close(flows["battery"], 3.6), "with little PV the export should run at its rate: {}".format(flows)) + soc, flows = simulate_minute(lossless(), controls, 8.0, 4.0, 0.4, 600) + failed += check(close(flows["battery"], 1.0), "with 4 kW of PV only 1 kW of the 5 kW limit is left for the battery: {}".format(flows)) + soc, flows = simulate_minute(lossless(), controls, 8.0, 6.0, 0.4, 600) + failed += check(close(flows["battery"], 0.0) and close(flows["clipped"], 1.0), "PV above the limit leaves nothing for the battery and clips: {}".format(flows)) + soc, flows = simulate_minute(lossless(), controls, 2.0, 0.0, 0.4, 600) + failed += check(close(flows["battery"], 0.0), "the export should stop at its target SoC: {}".format(flows)) + controls["export"]["rate"] = 0 + soc, flows = simulate_minute(lossless(), controls, 8.0, 3.0, 0.4, 600) + failed += check(close(flows["battery"], 0.0) and close(flows["grid"], -2.6), "a zero-rate export window freezes the battery and exports PV: {}".format(flows)) + return failed + + +def test_charge_window_and_losses(): + """A charge window charges from PV first then the grid, stops at its target, and pays the losses.""" + controls = {"charge": {"enable": True, "start_time": "23:30:00", "end_time": "05:30:00", "target_soc": 80, "rate": 3000}, "export": {"enable": False}, "reserve": 4} + failed = 0 + soc, flows = simulate_minute(lossless(), controls, 5.0, 0.0, 0.5, 60) + failed += check(close(flows["battery"], -3.0) and close(flows["grid"], 3.5), "grid should supply the charge and the load: {}".format(flows)) + soc, flows = simulate_minute(lossless(), controls, 8.0, 0.0, 0.5, 60) + failed += check(close(flows["battery"], 0.0), "the charge should stop at its target: {}".format(flows)) + soc, flows = simulate_minute(DUMMY_DEFAULTS, controls, 5.0, 0.0, 0.5, 60) + failed += check(close(soc, 5.0 + 3.0 / 60 * 0.96) and close(flows["grid"], 0.5 + 3.0 / 0.96), "charging should pay battery and inverter losses: {} {}".format(soc, flows)) + return failed + + +def test_in_window(): + """Windows are [start, end), may run past midnight, and an empty or unreadable window is never active.""" + cases = [(600, "09:00:00", "12:00:00", True), (720, "09:00:00", "12:00:00", False), (10, "23:30:00", "05:30:00", True), (720, "23:30:00", "05:30:00", False), (600, "10:00:00", "10:00:00", False), (600, "bad", "12:00:00", False)] + for minute, start, end, expected in cases: + if in_window(minute, start, end) != expected: + print("ERROR: in_window({}, {}, {}) should be {}".format(minute, start, end, expected)) + return 1 + return 0 + + +def test_component(): + """The component wires Predbat to its entities, obeys control writes, and simulates forwards.""" + base = MockBase() + dummy = DummyInverter(base, config={"battery_size": 8, "soc_initial": 50, "load": 0.5, "pv_peak": 0}) + failed = 0 + dummy.automatic_config() + failed += check(base.args.get("inverter_type") == ["DUMMY"], "automatic_config should select the DUMMY inverter type") + failed += check(base.args.get("soc_kw") == ["sensor.predbat_dummy_battery_soc"], "soc_kw should point at the dummy SoC sensor: {}".format(base.args.get("soc_kw"))) + failed += check(base.args.get("discharge_target_soc") == ["number.predbat_dummy_export_target_soc"], "discharge_target_soc should point at the dummy control") + + failed += check(dummy.update_control("switch.predbat_dummy_export_enable", "turn_on") and dummy.controls["export"]["enable"], "a switch write should enable the export") + dummy.update_control("select.predbat_dummy_export_start_time", "00:00:00") + dummy.update_control("select.predbat_dummy_export_end_time", "23:59:00") + dummy.update_control("number.predbat_dummy_export_target_soc", "25") + failed += check(dummy.controls["export"]["target_soc"] == 25.0, "a number write should set the target") + failed += check(not dummy.update_control("number.predbat_other_thing", 1), "a write to another entity should not be taken as a control") + failed += check(dummy.update_control("select.predbat_dummy_charge_start_time", "nonsense") and dummy.controls["charge"]["start_time"] == "00:00:00", "an unreadable time should be ignored") + + dummy.step(1000) + dummy.step(1060) + failed += check(close(dummy.soc_kwh, 2.0, 0.01), "an hour of export should take 8 kWh at 50% down to its 25% target: {}".format(dummy.soc_kwh)) + failed += check(dummy.totals["export"] > 1.0, "the export should be counted: {}".format(dummy.totals)) + dummy.publish() + failed += check(base.get_state_wrapper("sensor.predbat_dummy_battery_soc") == round(dummy.soc_kwh, 3), "the SoC sensor should be published") + return failed + + +def test_inverter_def_matches(): + """INVERTER_DEF["DUMMY"] carries the capabilities the model implements.""" + row = INVERTER_DEF.get("DUMMY", {}) + for key, value in DUMMY_CAPABILITIES.items(): + if row.get(key, None) != value: + print("ERROR: INVERTER_DEF['DUMMY'][{}] is {} but the model implements {}".format(key, row.get(key), value)) + return 1 + return 0 + + +def run_dummy_inverter_tests(my_predbat): + """Run every dummy inverter test, returning a non-zero count on failure.""" + failed = 0 + failed += test_eco() + failed += test_export_shares_the_inverter_limit() + failed += test_charge_window_and_losses() + failed += test_in_window() + failed += test_component() + failed += test_inverter_def_matches() + return failed diff --git a/apps/predbat/tests/test_replay_forward.py b/apps/predbat/tests/test_replay_forward.py new file mode 100644 index 000000000..4adc23dce --- /dev/null +++ b/apps/predbat/tests/test_replay_forward.py @@ -0,0 +1,925 @@ +# fmt: off +# pylint: disable=line-too-long +"""Unit tests for the forward replay of a Predbat log from a debug yaml (tests/replay_forward.py).""" + +import os +import tempfile +from datetime import datetime, timedelta, timezone +from types import SimpleNamespace + +from utils import MinuteArray +from tests.test_single_debug import apply_overrides +from tests.replay_forward import parse_windows, parse_log, shift_counter, set_export_window, summarise, first_window, plan_state_now, model_car_charging_now, rebuild_io_rates, run_soc, chart_replay, simulate_soc, install_logged_load_divergence, remove_logged_load_divergence, soc_rms_error, version_change, apply_logged_load_forecast, apply_logged_pv_forecast, parse_log, parse_override, rescan_rate_stats, counter_gain, crosses_midnight, shift_cumulative, shift_windows, roll_over_midnight, apply_run, today_values, apply_logged_rates, apply_logged_load_exact, apply_logged_pv_exact + +SAMPLE_LOG = """2026-10-01 08:30:00.575570: --------------- PredBat - update at 2026-10-01 08:30:00+01:00 with clock skew 0 minutes, minutes now 510 +2026-10-01 08:30:00.577646: Predbat /config/github.py repository springfall2008/batpred version v9.3.3 currently running, latest version is v9.3.3, latest beta is v9.3.3 +2026-10-01 08:30:02.135467: Current data so far today: load 5.74kWh, import 17.74kWh, export 4.57kWh, PV 0.21kWh +2026-10-01 08:30:02.324401: Today's load divergence 100.0%, in-day adjustment 92.66%, damping 0.95x, yesterday 88.64% today 100.0% blend 64.58% +2026-10-01 08:30:02.269308: Today's energy total net 13.17kWh, import 17.74kWh, export 4.57kWh, cost 66.82c, import 151.37c, export -84.54c, carbon 0.0kg +2026-10-01 08:30:02.366949: Inverter 0 SoC: 14.27kWh 85%, current charge rate 9200W, current discharge rate 9660W, current battery power -40W, current battery voltage 52.0V, grid power 6W, load power 506W, PV Power 558W +2026-10-01 08:30:02.468111: PV Forecast 44.6kWh and 10% Forecast 30.6kWh; PV cloud factor 0.2 +2026-10-01 08:30:02.469744: Load divergence over 8.0 hours mean 363.79W, min 254.4W, max 748.8W, std dev 73.34W, divergence 10.08% +2026-10-01 08:30:02.467699: Best export window [ 01-10 08:35:00 - 01-10 12:30:00 @ 18.5c 51.0% ] +2026-10-01 08:30:03.627292: Best export window [ 01-10 09:00:00 - 01-10 09:30:00 @ 18.5c 100.0% ] +2026-10-01 08:30:04.419814: Export windows filtered [ 01-10 09:00:00 - 01-10 12:00:00 @ 18.5c 55.0%, 01-10 13:00:00 - 01-10 13:30:00 @ 18.5c 84.0% ] +2026-10-01 08:30:05.663044: Next export window will be: 2026-10-01 09:00:00+01:00 - 2026-10-01 12:01:00+01:00 at reserve (0, 55, 1.0) +2026-10-01 08:30:05.663103: Inverter 0 Adjust force export to True, change times from 00:00:00 - 00:00:00 to 09:00:00 - 12:01:00 +2026-10-01 08:30:05.700000: Inverter 0 SoC: 14.20kWh 84%, current charge rate 9200W, current discharge rate 9660W, current battery power -40W, current battery voltage 52.0V, grid power 6W, load power 506W, PV Power 558W +2026-10-01 08:35:00.575570: --------------- PredBat - update at 2026-10-01 08:35:00+01:00 with clock skew 0 minutes, minutes now 515 +2026-10-01 08:35:02.366949: Inverter 0 SoC: 13.92kWh 83%, current charge rate 9200W, current discharge rate 9660W, current battery power 4930W, current battery voltage 52.0V, grid power 6W, load power 412W, PV Power 570W +2026-10-01 08:40:00.575570: --------------- PredBat - update at 2026-10-01 08:40:00+01:00 with clock skew 0 minutes, minutes now 520 +2026-10-01 08:40:01.000000: nothing the replay needs, so this run is dropped +""" + + +class FakeBat: + """The few attributes set_export_window touches.""" + + def __init__(self, rate_export=None): + """Create the stand-in.""" + self.rate_export = rate_export + self.export_window = None + self.isExporting = None + + +def test_parse_windows(): + """A window_as_text string parses back into start, end, rate and percent.""" + windows = parse_windows("[ 01-10 09:00:00 - 01-10 12:00:00 @ 18.5c 55.0%, 01-10 23:55:00 - 02-10 00:00:00 @ 8.43c 0.0%, 02-10 06:00:00 - 02-10 07:00:00 @ 16.5c 60.0% ]", "01-10") + if windows != [(540, 720, 18.5, 55.0), (1435, 1440, 8.43, 0.0), (1800, 1860, 16.5, 60.0)]: + print("ERROR: parse_windows gave {}".format(windows)) + return 1 + if first_window(windows[2:]) != "06:00+1d-07:00+1d @60%": + print("ERROR: a window tomorrow should be labelled as tomorrow: {}".format(first_window(windows[2:]))) + return 1 + if parse_windows("[ ]") != [] or first_window([]) != "-": + print("ERROR: an empty window list should parse to nothing") + return 1 + return 0 + + +def test_parse_log(): + """Each update line starts a run, a run keeps what it logged, and one with no SoC is dropped.""" + with tempfile.TemporaryDirectory() as folder: + path = os.path.join(folder, "predbat.log") + with open(path, "w") as handle: + handle.write(SAMPLE_LOG) + runs = parse_log(path) + if [run["minutes_now"] for run in runs] != [510, 515]: + print("ERROR: expected runs at 510 and 515, got {}".format([run["minutes_now"] for run in runs])) + return 1 + first, second = runs + failed = 0 + if first["soc"] != ("14.27", "85", "-40") or first["today"] != ("5.74", "17.74", "4.57", "0.21"): + print("ERROR: SoC or day counters parsed wrongly: {} {}".format(first["soc"], first["today"])) + failed = 1 + if first["version"] != "v9.3.3": + print("ERROR: version parsed wrongly: {}".format(first["version"])) + failed = 1 + if first["cost"] != "66.82": + print("ERROR: cost so far today parsed wrongly: {}".format(first["cost"])) + failed = 1 + if first["inday"] != "92.66" or first["divergence"] != "10.08" or first["force"] != ("True", "09", "00", "12", "01"): + print("ERROR: in-day adjustment, load divergence or force export parsed wrongly: {} {} {}".format(first["inday"], first["divergence"], first["force"])) + failed = 1 + if parse_windows(first["filtered"], "01-10") != [(540, 720, 18.5, 55.0), (780, 810, 18.5, 84.0)]: + print("ERROR: filtered windows parsed wrongly: {}".format(first["filtered"])) + failed = 1 + if parse_windows(first["in_force"], "01-10") != [(515, 750, 18.5, 51.0)]: + print("ERROR: the plan in force should be the run's first Best export window line: {}".format(first["in_force"])) + failed = 1 + if first["next_limit"] != ("0", "55", "1.0"): + print("ERROR: next export limit parsed wrongly: {}".format(first["next_limit"])) + failed = 1 + if second["filtered"] is not None or second["force"] is not None: + print("ERROR: a run that logged no re-plan should carry no windows") + failed = 1 + return failed + + +def test_shift_counter(): + """Advancing a backwards cumulative history ramps the gap up to the new counter and ages the rest.""" + history = MinuteArray({0: 10.0, 1: 9.0, 2: 8.0}, 3) + shifted = shift_counter(history, 2, 4.0) + expected = [14.0, 12.0, 10.0, 9.0, 8.0] + got = [shifted.get(key) for key in range(5)] + if got != expected or len(shifted) != 5: + print("ERROR: shift_counter gave {} expected {}".format(got, expected)) + return 1 + sparse = shift_counter({0: 3.0, 5: 1.0}, 2, 1.0) + if sparse != {0: 4.0, 1: 3.5, 2: 3.0, 7: 1.0}: + print("ERROR: a sparse dict history should shift its keys: {}".format(sparse)) + return 1 + if shift_counter(history, 0, 4.0) is not history: + print("ERROR: a zero-minute shift should leave the history alone") + return 1 + return 0 + + +def test_set_export_window(): + """The log's force export line becomes the inverter's window, and a False clears it.""" + bat = FakeBat(rate_export={540: 18.5}) + set_export_window(bat, ("True", "09", "00", "12", "01"), 545, ("0", "55", "1.0")) + if bat.export_window != [{"start": 540, "end": 721, "average": 18.5}] or not bat.isExporting or bat.export_limits != [(0, 55, 1.0)]: + print("ERROR: window not set from the force export line: {} {}".format(bat.export_window, bat.isExporting)) + return 1 + set_export_window(bat, ("True", "09", "00", "12", "01"), 500) + if bat.isExporting: + print("ERROR: a window that has not started should not be exporting") + return 1 + set_export_window(bat, ("True", "23", "00", "01", "00"), 1400) + if bat.export_window[0]["end"] != 25 * 60: + print("ERROR: a window crossing midnight should end the next day: {}".format(bat.export_window)) + return 1 + set_export_window(bat, ("False", "00", "00", "00", "00"), 545) + if bat.export_window != [] or bat.isExporting or bat.export_limits != []: + print("ERROR: force export False should clear the window") + return 1 + return 0 + + +def test_summarise(): + """Re-plans are counted as identical or as agreeing on the first window's start.""" + same = [(540, 720, 18.5, 55.0)] + rows = [ + {"replanned": True, "logged": same, "replayed": same}, + {"replanned": True, "logged": same, "replayed": [(540, 720, 18.5, 60.0)]}, + {"replanned": True, "logged": same, "replayed": [(600, 720, 18.5, 55.0)]}, + {"replanned": False, "logged": None, "replayed": None}, + ] + if summarise(rows) != (3, 1, 2): + print("ERROR: summarise gave {} expected (3, 1, 2)".format(summarise(rows))) + return 1 + rows.append({"replanned": True, "logged": same, "replayed": same, "after_version_change": True}) + if summarise(rows) != (3, 1, 2) or summarise(rows, after_version_change=True) != (1, 1, 1): + print("ERROR: rows after a version change should be counted separately: {} {}".format(summarise(rows), summarise(rows, after_version_change=True))) + return 1 + return 0 + + +def test_plan_state_now(): + """The plan's state at a minute, by the web plan's rules: export instructions first, then charge, then a car slot.""" + exports = [(540, 600, 18.5, 40.0), (600, 660, 18.5, 99.0), (660, 720, 18.5, 100.0), (720, 780, 18.5, 90.0), (1800, 1860, 18.5, 30.0)] + charges = [(0, 60, 7.6, 100.0), (60, 120, 7.6, 4.0), (120, 180, 7.6, 50.0), (180, 240, 7.6, 0.0), (660, 690, 7.6, 100.0)] + car = [(240, 300)] + # SoC 60%, reserve 4%; the last export window is tomorrow at 06:00, so it must not count at 06:00 today + cases = [ + (30, "Chrg"), + (90, "FrzChrg"), + (150, "HoldChrg"), + (200, None), + (250, "Car"), + (9 * 60, "Exp"), + (10 * 60 + 30, "FrzExp"), + (11 * 60 + 10, "Chrg"), + (12 * 60 + 30, "HoldExp"), + (6 * 60, None), + ] + for minute, expected in cases: + got = plan_state_now(charges, exports, minute, 60, 4, car) + if got != expected: + print("ERROR: plan_state_now at minute {} gave {} expected {}".format(minute, got, expected)) + return 1 + if plan_state_now(None, None, 600, 60, 4, None) is not None: + print("ERROR: no plan should mean plain demand") + return 1 + return 0 + + +def test_chart_replay(): + """A replay chart renders to a PNG without needing a display.""" + rows = [ + {"minutes_now": 540, "soc_percent": 80, "replanned": True, "logged": [(540, 600, 18.5, 40.0)], "replayed": [(570, 600, 18.5, 50.0)], "logged_charge": [], "replayed_charge": [(540, 570, 7.6, 100.0)], "reserve_percent": 4, "car_slots": [(540, 560)]}, + {"minutes_now": 545, "soc_percent": 78, "replanned": False, "logged": None, "replayed": None, "car_slots": [(540, 560)]}, + {"minutes_now": 550, "soc_percent": 75, "replanned": True, "logged": [(600, 660, 18.5, 99.0)], "replayed": [], "after_version_change": True}, + ] + with tempfile.TemporaryDirectory() as folder: + path = os.path.join(folder, "replay.png") + chart_replay(rows, path, title="test") + with open(path, "rb") as handle: + header = handle.read(8) + if header != b"\x89PNG\r\n\x1a\n": + print("ERROR: chart_replay did not write a PNG") + return 1 + return 0 + + +def test_simulate_soc(my_predbat): + """With no PV and no plan the battery covers the actual load, losing it plus its losses; no time means no change.""" + if simulate_soc(my_predbat, 5.0, 0, 0.0, 1.0) != 5.0: + print("ERROR: a zero-minute simulation should not move the SoC") + return 1 + missing = object() + saved = {key: getattr(my_predbat, key, missing) for key in ("charge_limit_best", "charge_window_best", "export_window_best", "export_limits_best", "soc_max", "reserve", "pv_forecast_minute_step", "load_minutes_step", "inverter_limit")} + try: + my_predbat.charge_limit_best, my_predbat.charge_window_best, my_predbat.export_window_best, my_predbat.export_limits_best = [], [], [], [] + my_predbat.soc_max = 10.0 + my_predbat.reserve = 0.5 + # The bare fixture has a zero inverter limit, which would stop the battery discharging at all + my_predbat.inverter_limit = 5000 / 60000.0 + my_predbat.pv_forecast_minute_step = {} + my_predbat.load_minutes_step = {} + soc = simulate_soc(my_predbat, 5.0, 30, 0.0, 1.0) + finally: + # Restore exactly, removing what the fixture did not have, so no later test sees this one's state + for key, value in saved.items(): + if value is missing: + delattr(my_predbat, key) + else: + setattr(my_predbat, key, value) + # 1 kWh of load drawn from the battery, divided by the discharge loss, so a little over 1 kWh + if not (3.8 <= soc <= 4.0): + print("ERROR: simulate_soc gave {} for 1 kWh of load from 5 kWh, expected a little under 4".format(soc)) + return 1 + return 0 + + +def test_logged_load_divergence(my_predbat): + """While installed, the logged divergence replaces the computed one; removing it restores the instance.""" + enabled = my_predbat.metric_load_divergence_enable + try: + install_logged_load_divergence(my_predbat) + my_predbat.replay_load_divergence = 0.16 + my_predbat.metric_load_divergence_enable = True + if my_predbat.get_load_divergence(0, {}) != 0.16: + print("ERROR: the logged load divergence was not used") + return 1 + my_predbat.metric_load_divergence_enable = False + if my_predbat.get_load_divergence(0, {}) is not None: + print("ERROR: a disabled load divergence should still read as None") + return 1 + finally: + remove_logged_load_divergence(my_predbat) + my_predbat.metric_load_divergence_enable = enabled + if "get_load_divergence" in my_predbat.__dict__ or "replay_load_divergence" in my_predbat.__dict__: + print("ERROR: removing the override left state on the instance") + return 1 + return 0 + + +def test_soc_rms_error(): + """The RMS SoC error compares simulated and logged SoC, and is None when nothing was simulated.""" + rows = [{"soc_percent": 50, "soc_sim_percent": 53}, {"soc_percent": 60, "soc_sim_percent": 56}, {"soc_percent": 70, "soc_sim_percent": None}] + if abs(soc_rms_error(rows) - (12.5 ** 0.5)) > 1e-9 or soc_rms_error([{"soc_percent": 1}]) is not None: + print("ERROR: soc_rms_error gave {}".format(soc_rms_error(rows))) + return 1 + return 0 + + +def test_version_change(): + """The first run logging a different version is found; runs without a version line are skipped over.""" + runs = [{"version": "v9.3.1"}, {}, {"version": "v9.3.1"}, {"version": "v9.3.3"}, {"version": "v9.3.3"}] + if version_change(runs) != (3, "v9.3.1", "v9.3.3") or version_change(runs[:3]) is not None: + print("ERROR: version_change gave {}".format(version_change(runs))) + return 1 + return 0 + + +class InputBat: + """The forecast attributes the replay-input helpers replace.""" + + def __init__(self): + """Start with a flat 0.1 kWh per 5 minutes load forecast and a flat PV forecast.""" + self.load_forecast = {minute: minute / 50.0 for minute in range(0, 24 * 60)} + self.pv_forecast_minute = {minute: 0.01 for minute in range(24 * 60)} + self.pv_forecast_minute10 = dict(self.pv_forecast_minute) + self.pv_forecast_minute90 = dict(self.pv_forecast_minute) + + +def test_replay_inputs(): + """Logged load and PV forecasts are parsed and replace the replay's own from the logged start onwards.""" + lines = """2026-10-01 09:05:00.000000: --------------- PredBat - update at 2026-10-01 09:05:00+01:00 with clock skew 0 minutes, minutes now 545 +2026-10-01 09:05:01.000000: Inverter 0 SoC: 10.0kWh 60%, current charge rate 9200W, current discharge rate 9660W, current battery power 0W +2026-10-01 09:05:01.100000: Replay input: PV forecast changed, 30-minute kWh from 09:00 p50 [1.5, 3.0] p10 [0.6, 1.2] p90 [] +2026-10-01 09:05:01.200000: Replay input: load forecast, 5-minute Wh from 09:05 [200, 50] +""" + with tempfile.TemporaryDirectory() as folder: + path = os.path.join(folder, "predbat.log") + with open(path, "w") as handle: + handle.write(lines) + run = parse_log(path)[0] + bat = InputBat() + apply_logged_load_forecast(bat, run["load_input"]) + apply_logged_pv_forecast(bat, run["pv_input"]) + failed = 0 + # Forecast at 09:05 was 10.9 kWh cumulative; the log adds 0.2 then 0.05 + if abs(bat.load_forecast[545] - 10.9) > 1e-9 or abs(bat.load_forecast[550] - 11.1) > 1e-9 or abs(bat.load_forecast[555] - 11.15) > 1e-9 or bat.load_forecast[100] != 2.0: + print("ERROR: logged load forecast applied wrongly: {} {} {}".format(bat.load_forecast[545], bat.load_forecast[550], bat.load_forecast[555])) + failed = 1 + if abs(bat.pv_forecast_minute[545] - 0.05) > 1e-9 or abs(bat.pv_forecast_minute[575] - 0.1) > 1e-9 or bat.pv_forecast_minute[700] != 0.01: + print("ERROR: logged PV forecast applied wrongly") + failed = 1 + if bat.pv_forecast_minute90[545] != 0.01: + print("ERROR: an empty logged series should leave that forecast alone") + failed = 1 + return failed + + +def test_parse_override(): + """Overrides read numbers and booleans as such, and anything else as text.""" + cases = [("pv_metric90_weight=0.25", ("pv_metric90_weight", 0.25)), ("forecast_hours=30", ("forecast_hours", 30)), ("calculate_pv90_plan=False", ("calculate_pv90_plan", False)), ("mode=eco", ("mode", "eco"))] + for text, expected in cases: + if parse_override(text) != expected: + print("ERROR: parse_override({}) gave {}".format(text, parse_override(text))) + return 1 + try: + parse_override("missing-equals") + except ValueError: + return 0 + print("ERROR: an override without = should be rejected") + return 1 + + +def test_apply_overrides(my_predbat): + """An override sets a known setting; an unknown name is rejected rather than silently creating an attribute.""" + saved = my_predbat.pv_metric90_weight + try: + apply_overrides(my_predbat, {"pv_metric90_weight": 0.25}) + if my_predbat.pv_metric90_weight != 0.25: + print("ERROR: the override was not applied") + return 1 + try: + apply_overrides(my_predbat, {"no_such_setting": 1}) + except ValueError: + return 0 + print("ERROR: an unknown setting should be rejected") + return 1 + finally: + my_predbat.pv_metric90_weight = saved + + +RATE_STATS_KEYS = ( + "minutes_now", + "forecast_minutes", + "rate_import", + "rate_import_base", + "rate_export", + "rate_export_base", + "rate_min", + "rate_max", + "rate_average", + "rate_min_minute", + "rate_max_minute", + "rate_min_forward", + "rate_min_base", + "rate_max_base", + "rate_export_min", + "rate_export_max", + "rate_export_average", + "rate_export_min_minute", + "rate_export_max_minute", + "rate_export_max_forward", +) + + +def test_rescan_rate_stats(my_predbat): + """The rate stats are taken from now, so a passed import peak and export high drop out of them as the clock moves.""" + missing = object() + saved = {key: getattr(my_predbat, key, missing) for key in RATE_STATS_KEYS} + try: + my_predbat.forecast_minutes = 24 * 60 + # Import 10p with a 30p peak 04:00-05:00; export 5p with a 20p high at the same time + import_rates = {minute: 30.0 if 240 <= minute < 300 else 10.0 for minute in range(3 * 24 * 60)} + export_rates = {minute: 20.0 if 240 <= minute < 300 else 5.0 for minute in range(3 * 24 * 60)} + my_predbat.rate_import, my_predbat.rate_import_base = import_rates, dict(import_rates) + my_predbat.rate_export, my_predbat.rate_export_base = export_rates, dict(export_rates) + my_predbat.minutes_now = 0 + rescan_rate_stats(my_predbat) + before = (my_predbat.rate_max, my_predbat.rate_max_base, my_predbat.rate_export_max, my_predbat.rate_export_max_forward[0]) + my_predbat.minutes_now = 360 + rescan_rate_stats(my_predbat) + after = (my_predbat.rate_max, my_predbat.rate_max_base, my_predbat.rate_export_max, my_predbat.rate_export_max_forward[360]) + forward_min = my_predbat.rate_min_forward[360] + finally: + for key, value in saved.items(): + if value is missing: + delattr(my_predbat, key) + else: + setattr(my_predbat, key, value) + if before != (30.0, 30.0, 20.0, 20.0): + print("ERROR: before the peak the stats should include it: {}".format(before)) + return 1 + if after != (10.0, 10.0, 5.0, 5.0) or forward_min != 10.0: + print("ERROR: after the peak the stats should not include it: {} forward min {}".format(after, forward_min)) + return 1 + return 0 + + +MIDNIGHT_LOG = """2026-10-03 23:55:00.000000: --------------- PredBat - update at 2026-10-03 23:55:00+01:00 with clock skew 0 minutes, minutes now 1435 +2026-10-03 23:55:01.000000: Current data so far today: load 6.64kWh, import 17.07kWh, export 14.88kWh, PV 3.99kWh +2026-10-03 23:55:01.100000: Inverter 0 SoC: 4.05kWh 22%, current charge rate 5500W, current discharge rate 5500W, current battery power 5506W +2026-10-04 00:00:00.000000: --------------- PredBat - update at 2026-10-04 00:00:00+01:00 with clock skew 0 minutes, minutes now 0 +2026-10-04 00:00:01.000000: Current data so far today: load 0.0kWh, import 0.0kWh, export 0.0kWh, PV 0.0kWh +2026-10-04 00:00:01.100000: Inverter 0 SoC: 3.56kWh 20%, current charge rate 5500W, current discharge rate 5500W, current battery power 5505W +2026-10-04 00:00:02.000000: Export windows filtered [ 04-10 00:25:00 - 04-10 00:30:00 @ 16.16p 24.0% ] +2026-10-04 00:00:03.000000: Inverter 0 SoC: 3.53kWh 20%, current charge rate 5500W, current discharge rate 5500W, current battery power 5505W +2026-10-04 00:00:04.000000: Starting comparison of tariffs +2026-10-04 00:01:00.000000: Current data so far today: load 9.9kWh, import 9.9kWh, export 9.9kWh, PV 9.9kWh +2026-10-04 00:01:01.000000: Export windows filtered [ 04-10 17:00:00 - 04-10 19:00:00 @ 29.0p 21.0% ] +""" + + +def test_parse_log_midnight(): + """A run keeps the SoC it planned from, and nothing logged by the midnight tariff comparison.""" + with tempfile.TemporaryDirectory() as folder: + path = os.path.join(folder, "predbat.log") + with open(path, "w") as handle: + handle.write(MIDNIGHT_LOG) + runs = parse_log(path) + midnight = runs[1] + failed = 0 + if midnight["soc"][0] != "3.56": + print("ERROR: the SoC logged before the plan should be kept, got {}".format(midnight["soc"])) + failed = 1 + if midnight["today"] != ("0.0", "0.0", "0.0", "0.0") or parse_windows(midnight["filtered"], "04-10") != [(25, 30, 16.16, 24.0)]: + print("ERROR: the tariff comparison overwrote the run's own plan: {} {}".format(midnight["today"], midnight["filtered"])) + failed = 1 + return failed + + +def test_counter_gain(): + """A day counter's gain is the difference, the reading itself across midnight, and nothing for a dip within a day.""" + if counter_gain("6.64", "6.61") != 6.64 - 6.61 or counter_gain("0.47", "6.64", new_day=True) != 0.47 or counter_gain(1.0, 1.0) != 0.0: + print("ERROR: counter_gain gave {} {}".format(counter_gain("6.64", "6.61"), counter_gain("0.47", "6.64", new_day=True))) + return 1 + if counter_gain("6.60", "6.64") != 0.0: + print("ERROR: a dip within a day should count as no gain, got {}".format(counter_gain("6.60", "6.64"))) + return 1 + if not crosses_midnight({"time": "2026-10-03 23:55:00+01:00"}, {"time": "2026-10-04 00:00:00+01:00"}) or crosses_midnight({"time": "2026-10-04 00:00:00+01:00"}, {"time": "2026-10-04 00:05:00+01:00"}): + print("ERROR: crosses_midnight should compare the runs' dates") + return 1 + return 0 + + +def test_shift_day_series(): + """Cumulative series restart from the new midnight; windows move back a day without touching the originals.""" + failed = 0 + shifted = shift_cumulative({0: 0.0, 1430: 9.5, 1440: 10.0, 1445: 10.25}, 1440) + if shifted != {-1440: -10.0, -10: -0.5, 0: 0.0, 5: 0.25}: + print("ERROR: shift_cumulative gave {}".format(shifted)) + failed = 1 + windows = [{"start": 1410, "end": 1440, "start_orig": 1380, "average": 7.62}] + moved = shift_windows(windows, 1440) + if moved != [{"start": -30, "end": 0, "start_orig": -60, "average": 7.62}] or windows[0]["start"] != 1410: + print("ERROR: shift_windows gave {} and left {}".format(moved, windows)) + failed = 1 + return failed + + +def test_roll_over_midnight(): + """Rolling over moves the minute-keyed state back a day, advances midnight and leaves the plan's own timestamp alone.""" + bat = SimpleNamespace( + rate_import={1435: 7.62, 1440: 7.62, 2880: 30.0}, + pv_forecast_minute={1500: 0.01}, + manual_charge_times=[1470], + load_forecast={0: 0.0, 1440: 10.0, 1445: 10.25}, + load_forecast_array=[{1440: 10.0, 1450: 10.5}], + charge_window_best=[{"start": 1470, "end": 1770, "average": 7.62}], + car_charging_slots=[[{"start": 1500, "end": 1530, "kwh": 2.0}]], + midnight_utc=datetime(2026, 10, 3, tzinfo=timezone.utc), + minutes_now=1435, + plan_last_updated_minutes=1430, + ) + roll_over_midnight(bat) + failed = 0 + if bat.rate_import != {-5: 7.62, 0: 7.62, 1440: 30.0} or bat.pv_forecast_minute != {60: 0.01} or bat.manual_charge_times != [30]: + print("ERROR: minute-keyed state not moved back a day: {} {} {}".format(bat.rate_import, bat.pv_forecast_minute, bat.manual_charge_times)) + failed = 1 + if bat.load_forecast[5] != 0.25 or bat.load_forecast_array != [{0: 0.0, 10: 0.5}]: + print("ERROR: the load forecast should count from the new midnight: {} {}".format(bat.load_forecast, bat.load_forecast_array)) + failed = 1 + if bat.charge_window_best[0]["start"] != 30 or bat.car_charging_slots[0][0]["end"] != 90: + print("ERROR: windows not moved back a day: {} {}".format(bat.charge_window_best, bat.car_charging_slots)) + failed = 1 + if bat.midnight_utc != datetime(2026, 10, 4, tzinfo=timezone.utc) or bat.minutes_now != -5 or bat.plan_last_updated_minutes != 1430: + print("ERROR: clock state wrong after the roll over: {} {} {}".format(bat.midnight_utc, bat.minutes_now, bat.plan_last_updated_minutes)) + failed = 1 + return failed + + +def test_set_export_window_after_midnight(): + """A window over midnight seen just after midnight started yesterday, so it is running now.""" + bat = FakeBat(rate_export={-15: 16.68}) + set_export_window(bat, ("True", "23", "45", "00", "01"), 0) + if bat.export_window != [{"start": -15, "end": 1, "average": 16.68}] or not bat.isExporting: + print("ERROR: a window over midnight seen after midnight should have started yesterday: {} {}".format(bat.export_window, bat.isExporting)) + return 1 + return 0 + + +INVALID_LOG = """2026-10-04 04:01:03.000000: --------------- PredBat - update at 2026-10-04 04:00:00+01:00 with clock skew 0 minutes, minutes now 240 +2026-10-04 04:01:18.000000: Inverter 0 SoC: 18.08kWh 100%, current charge rate 5500W, current discharge rate 5500W, current battery power 159W +2026-10-04 04:01:20.198077: Will recompute the plan as it is invalid +2026-10-04 04:01:20.198100: Recompute, previous plan is invalid... +2026-10-04 04:01:20.203586: Best export window [ 04-10 04:00:00 - 04-10 04:30:00 @ 14.95p 100.0% ] +2026-10-04 04:01:21.000000: Export windows filtered [ 04-10 06:00:00 - 04-10 07:00:00 @ 15.8p 63.0% ] +2026-10-04 12:05:16.706970: --------------- PredBat - update at 2026-10-04 12:05:00+01:00 with clock skew 0 minutes, minutes now 725 +2026-10-04 12:05:16.800000: Inverter 0 SoC: 16.20kWh 90%, current charge rate 5500W, current discharge rate 5500W, current battery power 159W +2026-10-04 12:05:16.900000: Sensor changes require a replan, will recompute the plan +2026-10-04 12:05:17.111032: Will recompute the plan as it is invalid +2026-10-04 12:05:17.111195: Recompute is saving previous plan... +2026-10-04 12:05:17.115425: Best export window [ 04-10 14:00:00 - 04-10 14:30:00 @ 7.45p 100.0% ] +2026-10-04 12:05:19.357686: Export windows filtered [ 04-10 16:50:00 - 04-10 19:00:00 @ 23.02p 29.0% ] +""" + + +def test_parse_log_invalid_plan(): + """Only a run whose plan was really invalid is marked invalid; no recomputing run's working window list is taken as the plan in force.""" + with tempfile.TemporaryDirectory() as folder: + path = os.path.join(folder, "predbat.log") + with open(path, "w") as handle: + handle.write(INVALID_LOG) + run, recompute = parse_log(path) + if not run.get("invalid") or run["in_force"] is not None or run["filtered"] is None: + print("ERROR: an invalid-plan run parsed wrongly: invalid {} in force {} filtered {}".format(run.get("invalid"), run["in_force"], run["filtered"])) + return 1 + # A sensor-triggered recompute logs the same "Will recompute" line, but its plan is valid and is compared with the new one + if recompute.get("invalid") or not recompute.get("recompute") or recompute["in_force"] is not None: + print("ERROR: a valid recompute parsed wrongly: invalid {} recompute {} in force {}".format(recompute.get("invalid"), recompute.get("recompute"), recompute["in_force"])) + return 1 + return 0 + + +def test_apply_run_clears_p90_signatures(): + """Each replayed run clears the p90 guard's signatures, as fetch does, so a p50-only PV change keeps the real p90.""" + bat = SimpleNamespace( + minutes_now=500, + now_utc=datetime(2026, 10, 4, 8, 20, tzinfo=timezone.utc), + load_minutes={}, + import_today={}, + export_today={}, + pv_today={}, + inverters=[], + rate_export={}, + pv_forecast_minute90_signatures=((1, 1.0, 0, 0), (1, 1.0, 0, 0)), + soc_max=18.08, + ) + apply_run(bat, {"today": None, "force": None, "time": "2026-10-04 08:20:00+01:00"}, {"time": "2026-10-04 08:25:00+01:00", "minutes_now": 505, "soc": ("10.0", "55", "0")}) + if bat.pv_forecast_minute90_signatures is not None or bat.minutes_now != 505: + print("ERROR: apply_run should clear the p90 signatures: {}".format(bat.pv_forecast_minute90_signatures)) + return 1 + return 0 + + +STATE_RATES_LOG = """2026-10-04 11:50:00.000000: --------------- PredBat - update at 2026-10-04 11:50:00+01:00 with clock skew 0 minutes, minutes now 710 +2026-10-04 11:50:01.000000: Replay input: rates changed, from 11:50 import [[0, 7.5], [10, 31.16]] 30 export [[0, 15.0]] 20 import_base [] 0 export_base [[0, 15.0]] 20 +2026-10-04 11:55:00.000000: --------------- PredBat - update at 2026-10-04 11:55:00+01:00 with clock skew 0 minutes, minutes now 715 +2026-10-04 11:55:01.000000: Current data so far today: load 3.96kWh, import 21.27kWh, export 8.57kWh, PV 3.46kWh +2026-10-04 11:55:01.100000: Replay input: state soc_kw 15.495 soc_max 18.08 inday 0.9763652840196139 cost_today 47.02738900000056 load_today 3.9639999999999986 import_today 21.27000000000001 export_today 8.570000000000007 pv_today None +2026-10-04 11:55:01.200000: Inverter 0 SoC: 15.50kWh 86%, current charge rate 9200W, current discharge rate 9660W, current battery power 0W +""" + + +def test_replay_state_and_rates(): + """The exact state line overrides the rounded values, and a rates change logged by a dropped run reaches the next run.""" + with tempfile.TemporaryDirectory() as folder: + path = os.path.join(folder, "predbat.log") + with open(path, "w") as handle: + handle.write(STATE_RATES_LOG) + runs = parse_log(path) + failed = 0 + if len(runs) != 1 or runs[0].get("rates") is None: + print("ERROR: the dropped run's rates should carry to the next run: {}".format(runs)) + return 1 + run = runs[0] + if run["state"]["inday"] != 0.9763652840196139 or run["state"]["pv_today"] is not None: + print("ERROR: state line parsed wrongly: {}".format(run["state"])) + failed = 1 + # pv_today is None in the state, so the counters fall back to the rounded line + if today_values(run) != ("3.96", "21.27", "8.57", "3.46"): + print("ERROR: today_values should fall back when the state lacks a counter: {}".format(today_values(run))) + failed = 1 + if today_values({"state": dict(run["state"], pv_today=3.46)}) != (3.9639999999999986, 21.27000000000001, 8.570000000000007, 3.46): + print("ERROR: today_values should prefer the exact state counters") + failed = 1 + inverter = SimpleNamespace(soc_kw=0, soc_percent=0) + bat = SimpleNamespace( + minutes_now=710, + now_utc=datetime(2026, 10, 4, 10, 50, tzinfo=timezone.utc), + load_minutes={}, + import_today={}, + export_today={}, + pv_today={}, + inverters=[inverter], + soc_max=18.0, + rate_import={minute: 20.0 for minute in range(0, 2000)}, + rate_export={minute: 5.0 for minute in range(0, 2000)}, + rate_import_base={minute: 20.0 for minute in range(0, 2000)}, + rate_export_base={}, + ) + apply_run(bat, {"today": None, "force": None, "time": "2026-10-04 11:50:00+01:00"}, run) + if bat.soc_kw != 15.495 or inverter.soc_kw != 15.495 or bat.soc_max != 18.08 or bat.load_inday_adjustment != 0.9763652840196139 or bat.cost_today_sofar != 47.02738900000056: + print("ERROR: exact state not applied: soc {} max {} inday {} cost {}".format(bat.soc_kw, bat.soc_max, bat.load_inday_adjustment, bat.cost_today_sofar)) + failed = 1 + # Rebuilt from 11:50: 7.5 for 10 minutes then 31.16 to 30 minutes, nothing after; before 11:50 untouched + if bat.rate_import[709] != 20.0 or bat.rate_import[710] != 7.5 or bat.rate_import[719] != 7.5 or bat.rate_import[720] != 31.16 or bat.rate_import[739] != 31.16 or 740 in bat.rate_import: + print("ERROR: import rates rebuilt wrongly") + failed = 1 + if bat.rate_export_base.get(729) != 15.0 or 730 in bat.rate_export_base or bat.rate_export[729] != 15.0 or 730 in bat.rate_export: + print("ERROR: export rates rebuilt wrongly") + failed = 1 + # An empty series empties the rates from the start, as the live rates were + if bat.rate_import_base.get(709) != 20.0 or 710 in bat.rate_import_base: + print("ERROR: an empty series should leave no rates from its start") + failed = 1 + return failed + + +def test_apply_logged_rates_from_before_midnight(): + """A rates line from the day before (carried over midnight by a dropped run) is moved back a day.""" + bat = SimpleNamespace(minutes_now=5, rate_import={}) + apply_logged_rates(bat, (23 * 60 + 55, {"import": ([(0, 10.0), (10, 20.0)], 20)})) + if bat.rate_import.get(-5) != 10.0 or bat.rate_import.get(5) != 20.0 or 15 in bat.rate_import: + print("ERROR: a rates line from before midnight applied wrongly: {}".format(sorted(bat.rate_import.items())[:3])) + return 1 + return 0 + + +def test_load_exact(): + """The exact load forecast line sets the two values per step the plan reads, removes ones logged None, and wins over the older slot line.""" + lines = """2026-10-04 19:30:00.000000: --------------- PredBat - update at 2026-10-04 19:30:00+01:00 with clock skew 0 minutes, minutes now 1170 +2026-10-04 19:30:01.000000: Inverter 0 SoC: 10.0kWh 60%, current charge rate 9200W, current discharge rate 9660W, current battery power 0W +2026-10-04 19:30:01.200000: Replay input: load forecast, cumulative kWh at each 5-minute step and the minute after from 19:30 [[12.3456, 12.3489], [12.4, None]] +""" + with tempfile.TemporaryDirectory() as folder: + path = os.path.join(folder, "predbat.log") + with open(path, "w") as handle: + handle.write(lines) + run = parse_log(path)[0] + bat = SimpleNamespace(load_forecast={minute: 1.0 for minute in range(1160, 1190)}) + apply_logged_load_exact(bat, run["load_exact"]) + forecast = bat.load_forecast + if forecast[1170] != 12.3456 or forecast[1171] != 12.3489 or forecast[1175] != 12.4 or 1176 in forecast or forecast[1172] != 1.0 or forecast[1160] != 1.0: + print("ERROR: exact load forecast applied wrongly: {}".format({minute: forecast.get(minute) for minute in (1170, 1171, 1172, 1175, 1176)})) + return 1 + return 0 + + +def test_load_compact(): + """The compact load line rebuilds each step's start and minute-after value exactly, in tenths of a Wh.""" + lines = """2026-10-06 10:00:00.000000: --------------- PredBat - update at 2026-10-06 10:00:00+01:00 with clock skew 0 minutes, minutes now 600 +2026-10-06 10:00:01.000000: Inverter 0 SoC: 10.0kWh 60%, current charge rate 9200W, current discharge rate 9660W, current battery power 0W +2026-10-06 10:00:01.200000: Replay input: load from 10:00 base 12345.6 Wh, Wh/5min [48.1/9.6, 47.9/9.5, -0.2/0.0] +""" + with tempfile.TemporaryDirectory() as folder: + path = os.path.join(folder, "predbat.log") + with open(path, "w") as handle: + handle.write(lines) + run = parse_log(path)[0] + bat = SimpleNamespace(load_forecast={minute: 1.0 for minute in range(590, 620)}) + apply_logged_load_exact(bat, run["load_exact"]) + expected = {600: 12.3456, 601: 12.3552, 605: 12.3937, 606: 12.4032, 610: 12.4416, 611: 12.4416, 602: 1.0} + got = {minute: bat.load_forecast.get(minute) for minute in expected} + if got != expected: + print("ERROR: compact load forecast applied wrongly: {}".format(got)) + return 1 + return 0 + + +def test_pv_exact(): + """The exact PV line sets each minute it covers from its runs, removes minutes logged None, and leaves the rest alone.""" + lines = """2026-10-04 19:30:00.000000: --------------- PredBat - update at 2026-10-04 19:30:00+01:00 with clock skew 0 minutes, minutes now 1170 +2026-10-04 19:30:01.000000: Inverter 0 SoC: 10.0kWh 60%, current charge rate 9200W, current discharge rate 9660W, current battery power 0W +2026-10-04 19:30:01.100000: Replay input: PV forecast changed, per-minute kWh runs from 19:30 p50 [[0.0094, 3], [None, 2]] p10 [[0.03333333333333333, 5]] p90 [[0.0, 5]] +""" + with tempfile.TemporaryDirectory() as folder: + path = os.path.join(folder, "predbat.log") + with open(path, "w") as handle: + handle.write(lines) + run = parse_log(path)[0] + bat = SimpleNamespace(pv_forecast_minute={minute: 1.0 for minute in range(1160, 1190)}, pv_forecast_minute10={}, pv_forecast_minute90={1200: 2.0}) + apply_logged_pv_exact(bat, run["pv_exact"]) + if bat.pv_forecast_minute[1172] != 0.0094 or 1173 in bat.pv_forecast_minute or 1174 in bat.pv_forecast_minute or bat.pv_forecast_minute[1175] != 1.0 or bat.pv_forecast_minute[1169] != 1.0: + print("ERROR: exact p50 applied wrongly") + return 1 + if bat.pv_forecast_minute10.get(1174) != 0.03333333333333333 or bat.pv_forecast_minute90.get(1174) != 0.0 or bat.pv_forecast_minute90.get(1200) != 2.0: + print("ERROR: exact p10/p90 applied wrongly") + return 1 + return 0 + + +def test_cars_input(): + """A logged car state is parsed, carried past a dropped run, and set on the instance by apply_run.""" + lines = """2026-10-05 17:25:00.000000: --------------- PredBat - update at 2026-10-05 17:25:00+01:00 with clock skew 0 minutes, minutes now 1045 +2026-10-05 17:25:01.000000: Replay input: cars changed {'car_charging_planned': [True], 'car_charging_soc': [33.11], 'car_charging_slots': [[{'start': 1290, 'end': 1350, 'kwh': 7.658, 'octopus': True}]], 'car_charging_limit_model': [9999.0]} +2026-10-05 17:25:41.000000: --------------- PredBat - update at 2026-10-05 17:25:00+01:00 with clock skew 0 minutes, minutes now 1045 +2026-10-05 17:25:42.000000: Inverter 0 SoC: 18.08kWh 100%, current charge rate 9200W, current discharge rate 9660W, current battery power 0W +""" + with tempfile.TemporaryDirectory() as folder: + path = os.path.join(folder, "predbat.log") + with open(path, "w") as handle: + handle.write(lines) + runs = parse_log(path) + if len(runs) != 1 or runs[0].get("cars", {}).get("car_charging_soc") != [33.11]: + print("ERROR: the dropped run's car state should carry to the next run: {}".format(runs)) + return 1 + bat = SimpleNamespace(minutes_now=1040, now_utc=datetime(2026, 10, 5, 16, 20, tzinfo=timezone.utc), soc_max=18.08, load_minutes={}, import_today={}, export_today={}, pv_today={}, inverters=[], rate_export={}, car_charging_planned=[False], car_charging_slots=[[]]) + apply_run(bat, {"today": None, "force": None, "time": "2026-10-05 17:20:00+01:00"}, runs[0]) + if bat.car_charging_planned != [True] or bat.car_charging_slots[0][0]["kwh"] != 7.658 or bat.car_charging_limit_model != [9999.0]: + print("ERROR: car state not applied: {}".format(vars(bat))) + return 1 + return 0 + + +def test_inverter_input(): + """A logged inverter state carries past a dropped run and replaces the reconstructed export window; the exact + divergence and the rates in force are applied too.""" + lines = """2026-10-05 23:31:30.000000: --------------- PredBat - update at 2026-10-05 23:30:00+01:00 with clock skew 0 minutes, minutes now 1410 +2026-10-05 23:31:31.000000: Replay input: inverter changed {'charge_window': [{'start': 1410, 'end': 1440, 'average': 0}], 'charge_limit': [18.08], 'isCharging': True, 'reserve': 0.723} +2026-10-05 23:32:00.000000: --------------- PredBat - update at 2026-10-05 23:30:00+01:00 with clock skew 0 minutes, minutes now 1410 +2026-10-05 23:32:01.000000: Inverter 0 SoC: 4.67kWh 26%, current charge rate 5500W, current discharge rate 5500W, current battery power 0W +2026-10-05 23:32:01.100000: Replay input: state soc_kw 4.665 soc_max 18.08 inday 0.95 cost_today -744.68 load_today 7.65 import_today 18.2 export_today 22.98 pv_today None charge_rate_now 0.0625 discharge_rate_now 0.09166666666666666 battery_temperature 23.0 +2026-10-05 23:32:01.200000: Load divergence over 2.0 hours mean 300W, min 100W, max 900W, std dev 95W, divergence 31.6% +2026-10-05 23:32:01.300000: Replay input: load divergence 0.31 +""" + with tempfile.TemporaryDirectory() as folder: + path = os.path.join(folder, "predbat.log") + with open(path, "w") as handle: + handle.write(lines) + runs = parse_log(path) + if len(runs) != 1 or runs[0].get("inverter", {}).get("charge_window") != [{"start": 1410, "end": 1440, "average": 0}]: + print("ERROR: the dropped run's inverter state should carry to the next run: {}".format(runs)) + return 1 + bat = SimpleNamespace(minutes_now=1400, now_utc=datetime(2026, 10, 5, 22, 20, tzinfo=timezone.utc), soc_max=18.08, load_minutes={}, import_today={}, export_today={}, pv_today={}, inverters=[], rate_export={}, charge_window=[], isCharging=False, replay_inverter_logged=True) + apply_run(bat, {"today": None, "force": None, "time": "2026-10-05 23:20:00+01:00"}, runs[0]) + if bat.charge_window != [{"start": 1410, "end": 1440, "average": 0}] or bat.isCharging is not True or bat.reserve != 0.723: + print("ERROR: inverter state not applied: {}".format(vars(bat))) + return 1 + if bat.charge_rate_now != 0.0625 or bat.discharge_rate_now != 0.09166666666666666 or bat.battery_temperature != 23 or not isinstance(bat.battery_temperature, int): + print("ERROR: the logged rates in force should be applied: {}".format(vars(bat))) + return 1 + if bat.replay_load_divergence != 0.31: + print("ERROR: the exact divergence should win over the rounded percentage: {}".format(bat.replay_load_divergence)) + return 1 + # Divergence off live: the plan used None, whatever the rounded percentage line says + off = dict(runs[0], divergence_exact="None") + apply_run(bat, {"today": None, "force": None, "time": "2026-10-05 23:30:00+01:00"}, off) + if bat.replay_load_divergence is not None: + print("ERROR: a logged None divergence should be applied as None, got {}".format(bat.replay_load_divergence)) + return 1 + return 0 + + +def test_model_car_charging_now(my_predbat): + """A car reporting charging now with no slot covering it is modelled to the end of the slot, as dynamic_load() does live.""" + saved = {name: getattr(my_predbat, name) for name in ("num_cars", "car_charging_now", "car_charging_slots", "car_charging_rate", "car_charging_now_slots", "minutes_now")} + try: + my_predbat.num_cars = 1 + my_predbat.car_charging_now = [True] + my_predbat.car_charging_slots = [[{"start": 8 * 60, "end": 9 * 60, "kwh": 7.0, "octopus": True}]] + my_predbat.car_charging_rate = [7.4] + my_predbat.minutes_now = 5 + model_car_charging_now(my_predbat) + slots = my_predbat.car_charging_now_slots + if len(slots) != 1 or len(slots[0]) != 1 or slots[0][0]["start"] != 5 or slots[0][0]["end"] != my_predbat.plan_interval_minutes: + print("ERROR: a car charging outside its plan should be modelled to the end of the slot, got {}".format(slots)) + return 1 + # Covered by a planned slot, or not charging: nothing modelled, and last run's slot is cleared + my_predbat.minutes_now = 8 * 60 + 5 + model_car_charging_now(my_predbat) + if my_predbat.car_charging_now_slots != [[]]: + print("ERROR: a car inside its planned slot should not be modelled again, got {}".format(my_predbat.car_charging_now_slots)) + return 1 + finally: + for name, value in saved.items(): + setattr(my_predbat, name, value) + return 0 + + +OLD_FORMAT_LOG = """2024-12-27 06:55:00.000000: --------------- PredBat - update at 2024-12-27 06:55:00+00:00 with clock skew 0 minutes, minutes now 415 +2024-12-27 06:55:01.000000: Current data so far today: load 5.04 kWh import 14.07 kWh export 0.0 kWh pv 0.0 kWh +2024-12-27 06:55:01.100000: Inverter 0 SOC: 1.9kW 20% Current charge rate 1314W Current discharge rate 2704W Current power -1134.0W Current voltage 52.64V +2024-12-27 06:55:01.200000: Inverter 1 SOC: 0.21kW 5% Current charge rate 0W Current discharge rate 2704W Current power -120.0W Current voltage 51.31V +2024-12-27 06:55:01.300000: Found 2 inverters totals: min reserve 0.55 current reserve 0.55 soc_max 13.696 soc 2.108 charge rate 1.31376 kW discharge rate 5.408 kW +2024-12-27 06:55:01.400000: Cars 1 charging from battery False planned [True], charging_now [False] smart [False], max_price [0.0]p +2024-12-27 06:55:01.500000: Car 0 charging plan is: [{'start': 1290, 'end': 1350, 'kwh': 7.658, 'average': 7.62, 'cost': 58.35, 'soc': 40.16, 'octopus': True}] +2024-12-27 06:55:01.600000: Car 0 charging plan is: [{'start': 0, 'end': 30, 'kwh': 1.0, 'average': 7.62, 'cost': 7.6, 'soc': 50.0, 'octopus': True}] +2024-12-27 06:55:01.700000: Octopus slots changed from [[]] to [[{'charge_in_kwh': -2.67, 'end': '2024-12-27T08:30:00+00:00', 'location': 'AT_HOME', 'source': 'smart-charge', 'start': '2024-12-27T08:00:00+00:00'}]] +2024-12-27 06:55:02.000000: Filtered charge windows [ 27-12 08:00:00 - 27-12 08:30:00 @ 7.62p 100% ] +2024-12-27 07:00:00.000000: --------------- PredBat - update at 2024-12-27 07:00:00+00:00 with clock skew 0 minutes, minutes now 420 +2024-12-27 07:00:01.000000: Inverter 0 SoC: 6.85kW 72%, current charge rate 3600W, current discharge rate 3780W, current battery power 366W, current battery voltage 53.3V +""" + + +def test_old_log_formats(): + """Older logs' line formats are read: the inverter total SoC, the spaced day totals, the re-plan marker that does not + need the filtered export line, the car plan and flags, the dispatch list, and kW-labelled SoC lines.""" + with tempfile.TemporaryDirectory() as folder: + path = os.path.join(folder, "predbat.log") + with open(path, "w") as handle: + handle.write(OLD_FORMAT_LOG) + runs = parse_log(path) + if len(runs) != 2: + print("ERROR: expected two runs from the old-format log, got {}".format(len(runs))) + return 1 + first, second = runs + if run_soc(first) != (2.108, 15) or first.get("today") != ("5.04", "14.07", "0.0", "0.0"): + print("ERROR: the inverter totals and old day totals should be read, got {} {}".format(run_soc(first), first.get("today"))) + return 1 + if not first.get("replan") or first.get("filtered") is not None: + print("ERROR: a 'Filtered charge windows' line should mark a re-plan without a filtered export line") + return 1 + if first.get("car_plans", {}).get(0, [{}])[0].get("start") != 1290 or first.get("car_flags") != ([True], [False]): + print("ERROR: the first car plan in a run and the car flags should be read, got {} {}".format(first.get("car_plans"), first.get("car_flags"))) + return 1 + if first.get("octopus_slots") != [[{"charge_in_kwh": -2.67, "end": "2024-12-27T08:30:00+00:00", "location": "AT_HOME", "source": "smart-charge", "start": "2024-12-27T08:00:00+00:00"}]]: + print("ERROR: the dispatch list should be read from the 'Octopus slots changed' line, got {}".format(first.get("octopus_slots"))) + return 1 + # The dispatch list is applied once and the instance keeps it, so a later run that logged no change has none + if run_soc(second) != (6.85, 72) or second.get("octopus_slots") is not None: + print("ERROR: a kW-labelled SoC line should be read, and only a run logging a change carry the dispatch list, got {} {}".format(run_soc(second), second.get("octopus_slots"))) + return 1 + bat = SimpleNamespace(minutes_now=400, now_utc=datetime(2024, 12, 27, 6, 40, tzinfo=timezone.utc), load_minutes={}, import_today={}, export_today={}, pv_today={}, inverters=[], rate_export={}, num_cars=1, soc_max=13.696, car_charging_slots=[[]], car_charging_planned=[False], car_charging_now=[True]) + apply_run(bat, {"today": None, "force": None, "time": "2024-12-27 06:50:00+00:00"}, first) + if bat.car_charging_slots[0][0]["start"] != 1290 or bat.car_charging_planned != [True] or bat.car_charging_now != [False] or bat.soc_kw != 2.108: + print("ERROR: the old-format car state and total SoC should be applied, got {}".format(vars(bat))) + return 1 + return 0 + + +MULTI_INVERTER_LOG = """2026-10-06 18:45:00.000000: --------------- PredBat - update at 2026-10-06 18:45:00+01:00 with clock skew 0 minutes, minutes now 1125 +2026-10-06 18:45:01.000000: Inverter 0 SoC: 6.46kWh 52%, current charge rate 2600W, current discharge rate 2675W, current battery power 2637W, current battery voltage 52.0V +2026-10-06 18:45:01.100000: Inverter 1 SoC: 6.76kWh 71%, current charge rate 2600W, current discharge rate 2730W, current battery power 2725W, current battery voltage 52.0V +2026-10-06 18:45:01.200000: Inverter 2 SoC: 5.32kWh 65%, current charge rate 3000W, current discharge rate 3150W, current battery power 3143W, current battery voltage 52.0V +2026-10-06 18:45:05.000000: Inverter 0 SoC: 6.30kWh 51%, current charge rate 2600W, current discharge rate 2675W, current battery power 2637W, current battery voltage 52.0V +""" + + +def test_multi_inverter_soc(): + """With several inverters and no totals line, the run's SoC is the sum of each inverter's first SoC line, and each + inverter is set to its own.""" + with tempfile.TemporaryDirectory() as folder: + path = os.path.join(folder, "predbat.log") + with open(path, "w") as handle: + handle.write(MULTI_INVERTER_LOG) + run = parse_log(path)[0] + soc_kw, percent = run_soc(run, 30.12) + if abs(soc_kw - 18.54) > 1e-9 or percent != 62: + print("ERROR: three inverters should total 18.54 kWh (62% of 30.12), got {} {}".format(soc_kw, percent)) + return 1 + inverters = [SimpleNamespace(soc_max=12.41), SimpleNamespace(soc_max=9.52), SimpleNamespace(soc_max=8.19)] + bat = SimpleNamespace(minutes_now=1120, now_utc=datetime(2026, 10, 6, 17, 40, tzinfo=timezone.utc), load_minutes={}, import_today={}, export_today={}, pv_today={}, inverters=inverters, rate_export={}, soc_max=30.12) + apply_run(bat, {"today": None, "force": None, "time": "2026-10-06 18:40:00+01:00"}, run) + if [inverter.soc_kw for inverter in inverters] != [6.46, 6.76, 5.32] or inverters[1].soc_percent != 71: + print("ERROR: each inverter should take its own logged SoC, got {}".format([vars(inverter) for inverter in inverters])) + return 1 + return 0 + + +def test_rebuild_io_rates(my_predbat): + """Rates rebuilt from a dispatch list start from the rates before any dispatch and lower the dispatch's minutes.""" + names = ("rate_import", "rate_import_no_io", "octopus_slots", "io_adjusted", "num_cars", "octopus_saving_slots", "octopus_free_slots") + saved = {name: getattr(my_predbat, name) for name in names} + try: + my_predbat.num_cars = 1 + my_predbat.rate_import_no_io = {minute: 30.0 for minute in range(-24 * 60, 48 * 60)} + my_predbat.octopus_saving_slots = [] + my_predbat.octopus_free_slots = [] + start = my_predbat.midnight_utc + timedelta(hours=22) + my_predbat.octopus_slots = [[{"start": start.isoformat(), "end": (start + timedelta(minutes=30)).isoformat(), "charge_in_kwh": -3.0, "source": "smart-charge", "location": "AT_HOME"}]] + rebuild_io_rates(my_predbat) + if my_predbat.rate_import[22 * 60] >= 30.0 or my_predbat.rate_import[21 * 60] != 30.0: + print("ERROR: the dispatch minutes should be cheaper and others unchanged, got {} {}".format(my_predbat.rate_import[22 * 60], my_predbat.rate_import[21 * 60])) + return 1 + finally: + for name, value in saved.items(): + setattr(my_predbat, name, value) + return 0 + + +def run_replay_forward_tests(my_predbat): + """Run every forward replay test, returning a non-zero count on failure.""" + failed = 0 + failed += test_parse_windows() + failed += test_parse_log() + failed += test_shift_counter() + failed += test_set_export_window() + failed += test_summarise() + failed += test_plan_state_now() + failed += test_chart_replay() + failed += test_simulate_soc(my_predbat) + failed += test_logged_load_divergence(my_predbat) + failed += test_soc_rms_error() + failed += test_version_change() + failed += test_replay_inputs() + failed += test_parse_override() + failed += test_apply_overrides(my_predbat) + failed += test_rescan_rate_stats(my_predbat) + failed += test_parse_log_midnight() + failed += test_counter_gain() + failed += test_shift_day_series() + failed += test_roll_over_midnight() + failed += test_set_export_window_after_midnight() + failed += test_parse_log_invalid_plan() + failed += test_apply_run_clears_p90_signatures() + failed += test_replay_state_and_rates() + failed += test_apply_logged_rates_from_before_midnight() + failed += test_load_exact() + failed += test_load_compact() + failed += test_pv_exact() + failed += test_cars_input() + failed += test_inverter_input() + failed += test_model_car_charging_now(my_predbat) + failed += test_old_log_formats() + failed += test_rebuild_io_rates(my_predbat) + failed += test_multi_inverter_soc() + return failed diff --git a/apps/predbat/tests/test_single_debug.py b/apps/predbat/tests/test_single_debug.py index 6d411b359..a3f7a42dc 100644 --- a/apps/predbat/tests/test_single_debug.py +++ b/apps/predbat/tests/test_single_debug.py @@ -42,18 +42,8 @@ def _dump_state_before_plan(my_predbat, filename): json.dump(state, handle, indent=2, sort_keys=True) -def run_single_debug(test_name, my_predbat, debug_file, expected_file=None, compare=False, debug=False, redo=False): - print("**** Running debug test {} ****\n".format(debug_file)) - # Will recompute the rates, load model and octopus slots if redo is True. This is useful for debugging a single test case, but the - # debug_cases regression suite exercise the same code path and produce the same result. - re_do_rates = redo - reset_load_model = redo - reload_octopus_slots = redo - load_override = 1.0 - my_predbat.load_user_config() - failed = False - - print("**** Test {} ****".format(test_name)) +def restore_debug_state(my_predbat, debug_file): + """Reset the shared fixture and load a debug yaml into it, leaving it ready to plan from.""" reset_inverter(my_predbat) # Some derived state is neither saved in the debug yaml (so read_debug_yaml cannot restore it) nor # reset by reset_inverter, so inside the full suite it leaks from a previous test and makes the debug @@ -76,6 +66,94 @@ def run_single_debug(test_name, my_predbat, debug_file, expected_file=None, comp my_predbat.save_restore_dir = "./" my_predbat.load_user_config() my_predbat.args["threads"] = 0 + + +def apply_overrides(my_predbat, overrides): + """Set each name=value override on the instance after a debug yaml is restored (--override), rejecting unknown names.""" + for name, value in (overrides or {}).items(): + if not hasattr(my_predbat, name): + raise ValueError("Unknown setting {} for --override".format(name)) + print("Override: {} = {} (was {})".format(name, value, getattr(my_predbat, name))) + setattr(my_predbat, name, value) + + +def rebuild_load_pv_models(my_predbat, load_override=1.0): + """Rebuild the stepped load and PV models from the history and forecasts now held on the instance.""" + my_predbat.load_minutes_step = my_predbat.step_data_history( + my_predbat.load_minutes, + my_predbat.minutes_now, + forward=False, + scale_today=my_predbat.load_inday_adjustment, + scale_fixed=my_predbat.load_scaling * load_override, + type_load=True, + load_forecast=my_predbat.load_forecast, + load_scaling_dynamic=my_predbat.load_scaling_dynamic, + cloud_factor=my_predbat.metric_load_divergence, + load_adjust=my_predbat.manual_load_adjust, + load_baseline=my_predbat.dynamic_load_baseline, + ) + my_predbat.load_minutes_step10 = my_predbat.step_data_history( + my_predbat.load_minutes, + my_predbat.minutes_now, + forward=False, + scale_today=my_predbat.load_inday_adjustment, + scale_fixed=my_predbat.load_scaling10 * load_override, + type_load=True, + load_forecast=my_predbat.load_forecast, + load_scaling_dynamic=my_predbat.load_scaling_dynamic, + cloud_factor=min(my_predbat.metric_load_divergence + 0.5, 1.0) if my_predbat.metric_load_divergence else None, + load_adjust=my_predbat.manual_load_adjust, + load_baseline=my_predbat.dynamic_load_baseline, + ) + my_predbat.pv_forecast_minute_step = my_predbat.step_data_history(my_predbat.pv_forecast_minute, my_predbat.minutes_now, forward=True, cloud_factor=my_predbat.metric_cloud_coverage) + my_predbat.pv_forecast_minute10_step = my_predbat.step_data_history( + my_predbat.pv_forecast_minute10, my_predbat.minutes_now, forward=True, cloud_factor=min(my_predbat.metric_cloud_coverage + CLOUD_FACTOR_PV10, 1.0) if my_predbat.metric_cloud_coverage else None, flip=True + ) + + +def rescan_rate_windows(my_predbat): + """Re-derive the rate thresholds and the candidate charge/export windows for the instance's current time.""" + # Set rate thresholds + if my_predbat.rate_import or my_predbat.rate_export: + print("Set rate thresholds") + my_predbat.set_rate_thresholds() + print("Result export {} import {}".format(my_predbat.rate_export_cost_threshold, my_predbat.rate_import_cost_threshold)) + + # Find discharging windows + if my_predbat.rate_export: + my_predbat.high_export_rates, export_lowest, export_highest = my_predbat.rate_scan_window(my_predbat.rate_export, 5, my_predbat.rate_export_cost_threshold, True, alt_rates=my_predbat.rate_import) + print("High export rate found rates in range {} to {} based on threshold {}".format(export_lowest, export_highest, my_predbat.rate_export_cost_threshold)) + # Update threshold automatically + if my_predbat.rate_high_threshold == 0 and export_lowest <= my_predbat.rate_export_max: + my_predbat.rate_export_cost_threshold = export_lowest + + # Find charging windows + if my_predbat.rate_import: + # Find charging window - mirrors fetch.py's fetch_sensor_data(), including the dawn + # light/dark split (#4699: this reimplementation used to omit pv_light_dark entirely, + # so a debug.yaml replay could never catch a regression in the split) + pv_light_dark = my_predbat.calc_pv_light_dark() + print("rate scan window import threshold rate {}".format(my_predbat.rate_import_cost_threshold)) + my_predbat.low_rates, lowest, highest = my_predbat.rate_scan_window(my_predbat.rate_import, 5, my_predbat.rate_import_cost_threshold, False, alt_rates=my_predbat.rate_export, pv_light_dark=pv_light_dark) + # Update threshold automatically + if my_predbat.rate_low_threshold == 0 and highest >= my_predbat.rate_min: + my_predbat.rate_import_cost_threshold = highest + + +def run_single_debug(test_name, my_predbat, debug_file, expected_file=None, compare=False, debug=False, redo=False, overrides=None): + print("**** Running debug test {} ****\n".format(debug_file)) + # Will recompute the rates, load model and octopus slots if redo is True. This is useful for debugging a single test case, but the + # debug_cases regression suite exercise the same code path and produce the same result. + re_do_rates = redo + reset_load_model = redo + reload_octopus_slots = redo + load_override = 1.0 + my_predbat.load_user_config() + failed = False + + print("**** Test {} ****".format(test_name)) + restore_debug_state(my_predbat, debug_file) + apply_overrides(my_predbat, overrides) # my_predbat.fetch_config_options() # Force off combine export XXX: @@ -136,31 +214,7 @@ def run_single_debug(test_name, my_predbat, debug_file, expected_file=None, comp print("Charge scaling 10 {} load scaling 10 {}".format(my_predbat.charge_scaling10, my_predbat.load_scaling10)) if re_do_rates: - # Set rate thresholds - if my_predbat.rate_import or my_predbat.rate_export: - print("Set rate thresholds") - my_predbat.set_rate_thresholds() - print("Result export {} import {}".format(my_predbat.rate_export_cost_threshold, my_predbat.rate_import_cost_threshold)) - - # Find discharging windows - if my_predbat.rate_export: - my_predbat.high_export_rates, export_lowest, export_highest = my_predbat.rate_scan_window(my_predbat.rate_export, 5, my_predbat.rate_export_cost_threshold, True, alt_rates=my_predbat.rate_import) - print("High export rate found rates in range {} to {} based on threshold {}".format(export_lowest, export_highest, my_predbat.rate_export_cost_threshold)) - # Update threshold automatically - if my_predbat.rate_high_threshold == 0 and export_lowest <= my_predbat.rate_export_max: - my_predbat.rate_export_cost_threshold = export_lowest - - # Find charging windows - if my_predbat.rate_import: - # Find charging window - mirrors fetch.py's fetch_sensor_data(), including the dawn - # light/dark split (#4699: this reimplementation used to omit pv_light_dark entirely, - # so a debug.yaml replay could never catch a regression in the split) - pv_light_dark = my_predbat.calc_pv_light_dark() - print("rate scan window import threshold rate {}".format(my_predbat.rate_import_cost_threshold)) - my_predbat.low_rates, lowest, highest = my_predbat.rate_scan_window(my_predbat.rate_import, 5, my_predbat.rate_import_cost_threshold, False, alt_rates=my_predbat.rate_export, pv_light_dark=pv_light_dark) - # Update threshold automatically - if my_predbat.rate_low_threshold == 0 and highest >= my_predbat.rate_min: - my_predbat.rate_import_cost_threshold = highest + rescan_rate_windows(my_predbat) else: print("don't re-do rates") @@ -182,36 +236,7 @@ def run_single_debug(test_name, my_predbat, debug_file, expected_file=None, comp # plan regression when the plans are identical. if reset_load_model: print("Reset load model") - my_predbat.load_minutes_step = my_predbat.step_data_history( - my_predbat.load_minutes, - my_predbat.minutes_now, - forward=False, - scale_today=my_predbat.load_inday_adjustment, - scale_fixed=my_predbat.load_scaling * load_override, - type_load=True, - load_forecast=my_predbat.load_forecast, - load_scaling_dynamic=my_predbat.load_scaling_dynamic, - cloud_factor=my_predbat.metric_load_divergence, - load_adjust=my_predbat.manual_load_adjust, - load_baseline=my_predbat.dynamic_load_baseline, - ) - my_predbat.load_minutes_step10 = my_predbat.step_data_history( - my_predbat.load_minutes, - my_predbat.minutes_now, - forward=False, - scale_today=my_predbat.load_inday_adjustment, - scale_fixed=my_predbat.load_scaling10 * load_override, - type_load=True, - load_forecast=my_predbat.load_forecast, - load_scaling_dynamic=my_predbat.load_scaling_dynamic, - cloud_factor=min(my_predbat.metric_load_divergence + 0.5, 1.0) if my_predbat.metric_load_divergence else None, - load_adjust=my_predbat.manual_load_adjust, - load_baseline=my_predbat.dynamic_load_baseline, - ) - my_predbat.pv_forecast_minute_step = my_predbat.step_data_history(my_predbat.pv_forecast_minute, my_predbat.minutes_now, forward=True, cloud_factor=my_predbat.metric_cloud_coverage) - my_predbat.pv_forecast_minute10_step = my_predbat.step_data_history( - my_predbat.pv_forecast_minute10, my_predbat.minutes_now, forward=True, cloud_factor=min(my_predbat.metric_cloud_coverage + CLOUD_FACTOR_PV10, 1.0) if my_predbat.metric_cloud_coverage else None, flip=True - ) + rebuild_load_pv_models(my_predbat, load_override) pv_step = my_predbat.pv_forecast_minute_step pv10_step = my_predbat.pv_forecast_minute10_step diff --git a/apps/predbat/unit_test.py b/apps/predbat/unit_test.py index a6f3daa32..20148e07f 100644 --- a/apps/predbat/unit_test.py +++ b/apps/predbat/unit_test.py @@ -80,6 +80,9 @@ from tests.test_solax import run_solax_tests from tests.test_sigenergy import run_sigenergy_tests from tests.test_single_debug import run_single_debug +from tests.replay_forward import replay_forward, summarise, chart_replay, soc_rms_error, parse_override +from tests.test_replay_forward import run_replay_forward_tests +from tests.test_dummy_inverter import run_dummy_inverter_tests from tests.test_saving_session import ( test_saving_session, test_saving_session_null_octopoints, @@ -706,6 +709,8 @@ def main(): ("ohme", test_ohme, "Ohme EV charger comprehensive tests (helper functions, client methods, API operations, event handlers)", False), ("givtcp_component", test_givtcp_component, "GivTCP component tests (entity publishing, automatic_config, event handlers)", False), ("debug_yaml_scope", run_debug_yaml_scope_tests, "create_debug_yaml() reachability/scope tests", False), + ("dummy_inverter", run_dummy_inverter_tests, "Simulated inverter and battery component (model physics, controls, automatic config)", False), + ("replay_forward", run_replay_forward_tests, "Forward replay of a log from a debug yaml (log parsing, history shifting, window comparison)", False), ("log_replay_inputs", run_log_replay_inputs_tests, "Replay-input log lines (forecasts, rates, plan state, cars, inverter)", False), ("memory_release", run_memory_release_tests, "glibc malloc_trim()/arena cap helper tests", False), ("inverter_write_poll", run_inverter_write_poll_tests, "Inverter write-and-poll timing tests", False), @@ -804,6 +809,11 @@ def main(): # Parse command line arguments parser = argparse.ArgumentParser(description="Predbat unit tests") parser.add_argument("--debug_file", action="store", help="Enable debug output") + parser.add_argument("--replay_log", action="store", help="With --debug_file: replay this Predbat log forwards from the debug yaml and compare each re-plan's export windows with the log's") + parser.add_argument("--replay_until", action="store", help="With --replay_log: stop the replay at the first HH:MM after the yaml (the next day if that time has passed)") + parser.add_argument("--replay_simulate", action="store_true", help="With --replay_log: simulate the battery under the replayed plan from actual PV and load, instead of taking SoC from the log") + parser.add_argument("--override", action="append", help="With --debug_file: override a setting after restoring the yaml, as name=value (repeatable), for what-if replays") + parser.add_argument("--replay_chart", action="store", help="With --replay_log: also write a PNG chart of SoC and the live vs replayed export plan to this file") parser.add_argument("--full_debug", action="store_true", help="Enable full debug output") parser.add_argument("--redo", action="store_true", help="Redo rates, load model and octopus slots for debug test") parser.add_argument("--compare", action="store_true", help="Run compare") @@ -895,8 +905,27 @@ def main(): ) sys.exit(0) + overrides = dict(parse_override(text) for text in (args.override or [])) + if args.debug_file and args.replay_log: + rows = replay_forward(my_predbat, args.debug_file, args.replay_log, until=args.replay_until, simulate=args.replay_simulate, overrides=overrides) + if args.replay_chart: + chart_replay(rows, args.replay_chart, title="Replay of {} from {}".format(os.path.basename(args.replay_log), os.path.basename(args.debug_file))) + print("Wrote replay chart to {}".format(args.replay_chart)) + for after in (False, True): + if after and not any(row.get("after_version_change") for row in rows): + break + label = " after the version change" if after else "" + replanned, identical, same_start = summarise(rows, after_version_change=after) + print("Replay: adopted plans{} - of {} re-plans, {} identical to the log and {} with the same first export window start".format(label, replanned, identical, same_start)) + replanned, identical, same_start = summarise(rows, logged="logged_candidate", replayed="replayed_candidate", after_version_change=after) + print("Replay: candidate plans{} - of {} re-plans, {} identical to the log and {} with the same first export window start".format(label, replanned, identical, same_start)) + rms = soc_rms_error(rows) + if rms is not None: + print("Replay: simulated SoC differs from the logged SoC by {:.2f}% RMS over {} runs".format(rms, len(rows))) + sys.exit(0) + if args.debug_file: - run_single_debug(args.debug_file, my_predbat, args.debug_file, compare=args.compare, debug=args.full_debug, redo=args.redo) + run_single_debug(args.debug_file, my_predbat, args.debug_file, compare=args.compare, debug=args.full_debug, redo=args.redo, overrides=overrides) sys.exit(0) # Collect tests to run based on arguments diff --git a/docs/developing.md b/docs/developing.md index c19dfee26..c25ce72c3 100644 --- a/docs/developing.md +++ b/docs/developing.md @@ -36,6 +36,55 @@ For coverage analysis install the 'coverage' library with Python, or use the ver 1. ./run_cov --quick 2. Open `htmlcov/index.html` in your web browser +### Replaying a log forwards from a debug yaml + +A debug yaml is one moment in time. When a bug report also attaches the log from the following hours, the replay can step through that log from the yaml and re-plan wherever the real Predbat did: + +```bash +cd coverage +./run_all --debug_file --replay_log [--replay_until HH:MM] +``` + +For each Predbat run in the log it sets the clock, SoC, the load/PV/import/export history and the inverter's programmed export window from the log, then re-plans on the runs where the log shows a re-plan. It prints the first export window the log recorded next to the one it computed, and a summary of how many re-plans matched. The PV forecast is the one in the yaml, because the log records only its total. + +Newer Predbat versions also log `Replay input:` lines, and the replay uses them wherever a run has them. They carry the load and PV forecasts, the values each plan starts from (SoC, in-day adjustment, cost so far, the day counters, the charge and discharge rates in force and the battery temperature) at full precision, the exact load divergence, and, whenever they change, the rates, the car state and the inverter's programmed state. Without them, the replay drifts from the live plans as the day goes on. + +There are two modes: + +- **Exact replay** (the default) takes the battery SoC from the log at every run, so each re-plan starts from exactly what the live system saw. Use it to check the replay reproduces the live plans before changing anything. +- **Simulated** (`--replay_simulate`) steps the battery forward itself under the replayed plan, using the actual PV and load from the log and Predbat's own battery and inverter model (rate curves, losses, reserve, the inverter and export limits). Use it once the code is changed: the SoC then follows the changed plan instead of being pinned to what the unchanged code did. + +`--override name=value` (repeatable) changes a setting after the yaml is restored, for what-if replays - for example `--override pv_metric90_weight=0.25`. It works for a plain `--debug_file` replay as well. + +`--replay_chart ` draws the actual SoC (and the simulated SoC, when simulating) against the export targets of the live and replayed plans, and a timeline of what each plan says at every run in the web plan's terms (Chrg, HoldChrg, FrzChrg, Exp, HoldExp, FrzExp, car), with a lane for the car's planned charging. + +In simulated mode the replay also prints the RMS difference between its simulated SoC and the logged SoC, a single number for how faithfully it is tracking the real battery. + +The replay carries on across midnight, so a yaml from late evening can be replayed through the whole of the next day. At midnight it moves everything held as minutes from midnight (rates, forecasts, plan windows) back a day, and the start-of-day re-plan happens as it does live. Rates the live system fetched after the yaml was written, such as the next day-ahead prices, are not in the yaml. The replay takes them from the log's `Replay input: rates changed` lines; a log without those lines plans on rates that run out early. `--replay_until HH:MM` stops at the first such time after the yaml. + +Where the replay matches the log it can be used for what-if experiments; where it does not, the first run that diverges shows what the log carries that the yaml did not. The log should come from a similar Predbat version; a version change part way through is marked, and the plans after it are counted separately. + +### The dummy inverter + +For a demo, or to run Predbat end to end without real hardware, the `dummy_inverter` component simulates a hybrid inverter and battery. Add a block to `apps.yaml` and it publishes its own sensors and controls and points Predbat's inverter settings at them: + +```yaml +dummy_inverter: + battery_size: 10 # kWh usable + battery_rate_max: 3600 # W, charge and discharge + inverter_limit: 5000 # W, AC output shared by PV and battery + export_limit: 5000 # W + battery_loss: 0.96 + battery_loss_discharge: 0.96 + inverter_loss: 0.96 + reserve: 4 # % + soc_initial: 50 # % + pv_peak: 4.0 # kW, clear-sky curve used when there is no PV forecast + load: 0.4 # kW, or a list of 24 hourly values +``` + +Every setting is optional. The model steps once a minute: the battery charges and discharges within its rate and losses, PV and battery share the inverter limit with PV first, export is capped at the export limit, and PV with nowhere to go is clipped (published as `sensor.predbat_dummy_clipped_power` and `_clipped_lifetime`). Predbat's charge and export windows are obeyed, a zero-rate window freezes the battery, and outside a window it runs self-consumption. PV comes from Predbat's forecast when one is configured. The simulation state is not saved, so a restart starts again from `soc_initial`. + ### Finding test order dependencies All tests run against one shared `PredBat`/Home Assistant fixture (see `create_predbat()` in `unit_test.py`), so a test that mutates shared state and doesn't fully restore it can make a *later* test fail - a bug in the test suite itself, not in Predbat (see issue [#5079](https://github.com/springfall2008/batpred/issues/5079)). These only show up when the two tests happen to run in that order, so a clean `./run_all` doesn't prove there isn't one lurking. diff --git a/tools/debug-journal.md b/tools/debug-journal.md index 0e0835d18..278a70582 100644 --- a/tools/debug-journal.md +++ b/tools/debug-journal.md @@ -32,6 +32,34 @@ Two lines in that output are normal and are not the reporter's bug: - `Prediction kernel stale binary ... - using Python engine` — the local C++ kernel is older than the Python side expects, so the pure-Python engine runs instead. The plan is still correct, just slower. - `Config item ... is below the minimum ... - clamping to ...` — routine clamping of an out-of-range setting. +### Replaying a log forwards from a debug yaml + +`./run_all --debug_file X.yaml --replay_log predbat.log` restores the yaml, then steps through the log's later runs, re-planning wherever the live system did and comparing each plan with the logged one (`tests/replay_forward.py`, PR #5363; flags in `docs/developing.md`). It is a work in progress: each mismatch it shows is either a bug or a missing input to log next. + +**You can use it to debug issues of the form** (rather than with a plain `--debug_file` replay): + +- **"At time T the plan did X"**, where T is after the yaml was taken: replay from an earlier yaml up to T and read the plan it made then (GH#5423: a manual demand slot at 19:00 planned as demand then export, with a 17:00 yaml). +- **"The plan kept changing"**: a window sliding later on every re-plan, a decision flipping back and forth (GH#4865: an early export whose start slid by the hour). +- **"It behaved differently overnight / around the car / after midnight"**: Intelligent dispatches, a car plugging in, the midnight rollover - things that happen between snapshots. +- **"Does the fix help on the reporter's real day?"**: replay their log in simulated mode on the fixed branch and compare the timeline with the live one. +- **"Would setting S have changed it?"**: `--override name=value` re-runs the day with it changed. + +It is not worth it when the log does not run past the yaml's time (common on bug reports: the attached log often ends where the yaml was taken), or when the question is about a single moment the yaml already captures. + +**Picking the files.** The yaml must be written *before* the moment in question and *after* any `apps.yaml` change or restart in between - the replay follows the yaml's settings and cannot follow a config reload. Concatenate rotated logs in time order (`predbat.02.log predbat.01.log predbat.log`). Rolling snapshots (`debug/predbat_debug_YYYYMMDD-HHMMSS.yaml.txt`) and logs rotate away within a few days, so copy what you need early. + +**Exact or simulated.** Exact mode (the default) takes the SoC from the log every run, so it tests whether the replay reproduces the live plans: on a log with the `Replay input:` lines (PR #5427) it matched every plan and cost line for line over whole days (Sigenergy, IOG, 5-8 Oct 2026). Simulated mode (`--replay_simulate`) steps the battery with Predbat's own model, so a changed plan has consequences: use it to try a fix or setting, and read its SoC RMS as a rough guide (0.8-2% on a full-input log). + +**Reading the output.** The summary counts compare **export windows only** - `--replay_chart` draws a timeline of every state (charge, hold, freeze, export, car) for live and replay, and is the quicker way to see where they part. For costs, diff the `predict base/best` lines of the live log against the replay's own `predbat.log` (it marks each run `Replay of run at ...`). + +Traps found so far: + +- **Older logs replay only approximately.** Without the `Replay input:` lines the forecasts stay as the yaml had them and the car, dispatch and SoC state come from the human-readable lines (read back to v8.8). The replay prints a note saying so; expect the first few re-plans to match and later ones to drift. +- **Multi-inverter systems:** the run's SoC is the sum of each inverter's own SoC line (GH#5423, three GivEnergy inverters; before 8 Oct the replay used inverter 0 alone and nothing matched). +- **Restarts and mid-run changes.** A restart resets the live plan in force, and a car plugging in mid-run makes live re-plan twice in one run; the replay folds both into one run, so the next keep-or-switch decision can differ. +- **Simulated SoC error cannot tune battery settings.** Changing a loss or rate setting also changes the plan, so the simulated battery follows different plans from live and the RMS gets worse even for a more accurate value (8 Oct sweep). Measure efficiencies from the log directly instead (battery power and SoC change over a charge window). +- **Every 8 hours the config refresh forces an extra run, and the log's wording hides which recomputes are invalid.** `Will recompute the plan as it is invalid` is logged for every recompute; only `Recompute, previous plan is invalid...` (against `Recompute is saving previous plan...`) says the plan really was invalid. Any recomputing run's first `Best export window` is the re-plan's fresh list, not the plan in force. + ## Debug yaml can contain real secrets A `predbat_debug.yaml` or debug-history snapshot attached to a bug report can carry live, unredacted credentials. Read it locally; never quote a raw block from one in a public comment without checking it first. @@ -154,6 +182,7 @@ Grep for the named symbol rather than trusting a line number. | Report | Start here | |--------|-----------| +| The plan did something **later than the debug yaml was taken**, or **kept changing** through the day (a window sliding, a decision flip-flopping, something going wrong overnight or around the car) | A forward log replay from an earlier yaml through the attached log - see "Replaying a log forwards from a debug yaml" above for which files to pick and which mode to use. Needs a log that runs past the yaml's time. | | `Failed to create inverter 0: argument of type 'int' is not iterable` (or the 3.11+ wording `'int' is not a container or iterable`), then `Failed to fetch inverter data, not able to compute a plan` | A literal numeric `reserve:` in apps.yaml, e.g. `reserve: - 1`, instead of an entity id — common on inverter types with no reserve entity (reported on Huawei). `reserve_device_bounds()` (PR #4956, so v8.55.1+ only; v8.55.0 is fine) resolves the value and passes it straight to `get_state_wrapper()` as an entity id, which evaluates `"$" in entity_id` (`predbat.py:190`) unguarded and raises `TypeError`. **Fixed in PR #5005 (v9.0.2)** for the whole class, not just this call site: `get_state_wrapper()` and `set_state_wrapper()` now log `Warn: ... is a fixed value, not an entity id` and return the default / `False` instead of raising, so current main degrades the literal to an unread setting rather than crashing. Keep the crash signature for pre-v9.0.2 versions, where the bisect still reads v8.55.0 works, v8.55.1/v9.0.0/v9.0.1 fail with the same apps.yaml. Workaround (still the right one at any version): delete the `reserve:` line or point it at an entity — lossless on `has_reserve_soc: False` types, where the literal only feeds `reserve_percent_current = max(literal, battery_min_soc)` and a value at or below `battery_min_soc` (default 4) is inert. The same fault arrives in two shapes (GH#5033, GE/GivTCP + Solis): the main create path wraps `Inverter()` in try/except (`execute.py`) and logs `Failed to create inverter N: ...`, but `balance_inverters()` re-creates every inverter each cycle with `Inverter(self, id, quiet=True)` and **no try/except**, so on a multi-inverter setup the TypeError propagates through `timer_tick` as a bare traceback through `balance_inverters → Inverter __init__ → reserve_device_bounds → get_state_wrapper` — and it re-crashes every cycle even while the main path reports cleanly. A report showing a timer_tick traceback with `balance_inverters` in the stack is the same apps.yaml fault (pre-v9.0.2; the #5005 guard removes the crash source from both paths). Since PR #5149 (merged 2026-09-19) there is no unguarded balance-path construction at all: `balance_inverters()` is a pure function in `utils.py` driven from `rebalance_inverter_rates()` on the inverter poll (SoC balancing defaults off, `balance_inverters_enable`), and the single `Inverter(self, id)` construction site in `execute.py` is itself wrapped in try/except — so a bare traceback through a balance path is pre-#5149 only. | | `Error: You have not set load_today or load_forecast in apps.yaml, you will have no load data` then `Error: Exception raised ValueError` every cycle, and the plan/SoC stop updating | `fetch_sensor_data()` raises a bare `raise ValueError` (fetch.py) when neither arg resolves and nothing in the fetch path catches it — the raise unwinds the whole cycle from the fetch call site (`predbat.py`, `sensor_force_replan = self.fetch_sensor_data()`), so inverter reads, the plan and every sensor publish are skipped, and the generic `Error: Exception raised` handler catches it (GH#5092). The message and the `Error: load_today not set correctly` status both point at apps.yaml, but cloud components set `load_today` at runtime (Solis `automatic_config()`, GE Cloud `async_automatic_config()`, `sunsynk_const.py` maps it too), so during a component startup delay there is nothing in apps.yaml to fix — this is the fetch-side end of the Solis startup-outage family (see the Solis row for why the delay happens; check the Components panel for startup backoff before telling the user to edit apps.yaml). No graceful fallback exists: `self.load_minutes` persists in memory only once a previous fetch has succeeded, so a restart into a not-yet-configured component has nothing to fall back on; any fix has to decide what the planner runs on for that cycle (maintainer call on #5092). | | A startup burst of `Warn: Failed to decode response from http:///api/history/period/...` then `Error: Too many API errors, stopping`, `Error: Web Socket failed to reconnect, stopping....`, `Info: HA interface stopped` — and Predbat then sits "stopped but running", web answering `/api/ping` 500 | The REST-layer **consecutive** error counter in `HAInterface.api_call()` (`ha.py`), not the websocket: a non-JSON response — which is what HA's 404 page surfaces as (`JSONDecodeError`) — plus every timeout or connection error increments `api_errors`, it resets **only on a fully successful call**, has no time decay, and at 10 calls `fatal_error_occurred()` (deliberate design since #2110 as a recovery mechanism). The websocket lines are the consequence, not the cause — the socket loop exits on `fatal_error`, waits 5s to reconnect, hits the outer break and logs the two stopping lines — so a websocket that was healthy all along is dragged down by REST-only 404s on the history endpoint. The threshold is reachable within one startup fetch: `get_history()` fetches each window in `HISTORY_CHUNK_DAYS` = 3-day chunks with nothing marking a chunk handled, so an entity's window is `ceil(max_days_previous/3)` consecutive calls (`days_previous` defaults `7` → 8 days → 3 calls per entity — `days_previous: 28+` reaches the 10 from one entity), and the boot-time full fetch is scheduled immediately at init (`update_time_loop` first fire `datetime.now()`, `predbat.py`), so a few entities' 404s back to back reach 10 in seconds. A non-2xx response **with a JSON body does not count** — it parses and is treated as data (degenerate, untested). While `fatal_error` is set `is_running()` reads False so `/api/ping` answers 500 while the web component keeps serving; standalone/Docker `stop_all()` still exits code 0 (per-thread join bounded at 5 min), so an `on-failure` supervisor policy does not restart it and the ping can answer 500 for minutes during shutdown — the official add-on wrapper restarts after ~20s. The fix is a maintainer design call in the counter (per-endpoint counting, or retry/backoff on history fetches) plus new tests, since existing tests assert the current behaviour. Related, not duplicate: #5134 (failed interface init blocks 10 min in `wait_api_started` — opposite mechanism, same "HA not ready at startup" family). |