From ce5eb3bc2335ef5d47298d3e61ac5866a5c748b3 Mon Sep 17 00:00:00 2001 From: Jens Ahrensfeld Date: Fri, 10 Jul 2026 22:28:01 +0200 Subject: [PATCH] log: Sud lifecycle transitions and stirrer/heater connect state Logs load/start/pause/continue/stop/entering-step/wait-user/finished on Sud (components/sud.py) and connected/disconnected on StirrerTask/HeaterTask, using the self.log added earlier. SudForecastEstimator.estimate() (components/sud_forecast.py) drives its own throwaway Sud through an entire schedule in a tight loop (no real waiting) to predict its duration, and re-runs that on every real step transition too - since it's still a Sud, it logged through the exact same "Sud" logger as the real, server-driven one, making an instant internal forecast run indistinguishable in the log from an actual brew. Gave it its own "SudForecastEstimator" logger, silenced to WARNING by default, so only the real Sud's transitions show up. --- components/sud.py | 8 ++++++++ components/sud_forecast.py | 10 ++++++++++ tasks/heater.py | 1 + tasks/stirrer.py | 1 + 4 files changed, 20 insertions(+) diff --git a/components/sud.py b/components/sud.py index 5a5e9a2..8e2cb75 100644 --- a/components/sud.py +++ b/components/sud.py @@ -154,6 +154,7 @@ class Sud(AttributeChange): self._data = data self._reset_run_state() + self.log.info("Loaded '{}'".format(self.name)) return True def derive_plant_params(self, grain_mass, water_mass): @@ -183,11 +184,13 @@ class Sud(AttributeChange): if self.state == SudState.PAUSED: self.state = self._paused_from self._paused_from = None + self.log.info("Continued") return if self.state not in (SudState.IDLE, SudState.DONE): return self.index = -1 self.elapsed = 0.0 + self.log.info("Started") self._advance() def pause(self): @@ -196,11 +199,13 @@ class Sud(AttributeChange): if self.state in (SudState.RAMPING, SudState.HOLDING): self._paused_from = self.state self.state = SudState.PAUSED + self.log.info("Paused") def stop(self): """Aborts the run, discarding progress back to IDLE.""" if self.state not in (SudState.IDLE, SudState.DONE): self._reset_run_state() + self.log.info("Stopped") def confirm(self): if self.state == SudState.WAIT_USER: @@ -243,6 +248,7 @@ class Sud(AttributeChange): self.state = SudState.DONE self.user_message = None self.step = None + self.log.info("Finished") return next_step = self.schedule[self.index] @@ -254,9 +260,11 @@ class Sud(AttributeChange): self.state = SudState.RAMPING self.user_message = next_step.get('user_message') self.step = next_step + self.log.info("Entering step {} ({})".format(next_step['number'], next_step.get('descr'))) def _finish_step(self): if self.step.get('user_wait_for_continue', False): self.state = SudState.WAIT_USER + self.log.info("Waiting for user interaction") else: self._advance() diff --git a/components/sud_forecast.py b/components/sud_forecast.py index 7f2dd87..34b993c 100644 --- a/components/sud_forecast.py +++ b/components/sud_forecast.py @@ -1,3 +1,4 @@ +import logging from components.plant import Pot from components.pid import PidFactory from components.sud import Sud, SudState @@ -7,6 +8,14 @@ from components.sud import Sud, SudState # simulation forever - the estimate is simply cut off there. MAX_TICKS = 200000 +# estimate() below drives a throwaway Sud through an entire schedule in a +# tight loop (no real waiting) purely to predict its duration - since it's +# still a Sud, it would otherwise log through the exact same "Sud" logger +# the real, server-driven one uses (components/sud.py's self.log), making +# an instant internal forecast run indistinguishable in the log from an +# actual brew. Quiet by default; raise this logger's own level to see it. +logging.getLogger('SudForecastEstimator').setLevel(logging.WARNING) + # Mirrors tasks/heater.py's own pulse_period_s - HeaterTask duty-cycles its # device's discrete power steps over a rolling window this many *real* # seconds wide, regardless of warp factor (see estimate()'s actuate() @@ -95,6 +104,7 @@ class SudForecastEstimator: start_theta = self.theta_amb sud = Sud(self.pot_config) + sud.log = logging.getLogger('SudForecastEstimator') if not sud.load(doc) or not sud.schedule: return [0.0], [start_theta], SudState.DONE, {} diff --git a/tasks/heater.py b/tasks/heater.py index 824b3ea..2d33056 100755 --- a/tasks/heater.py +++ b/tasks/heater.py @@ -33,6 +33,7 @@ class HeaterTask(ATask): self._on_connected_changed = callback def on_connected_changed(self, value): + self.log.info("Connected" if value else "Disconnected") fire_and_forget(self.send({'Connected': value})) if self._on_connected_changed: self._on_connected_changed(value) diff --git a/tasks/stirrer.py b/tasks/stirrer.py index a028580..cfc9cad 100644 --- a/tasks/stirrer.py +++ b/tasks/stirrer.py @@ -33,6 +33,7 @@ class StirrerTask(ATask): self._on_connected_changed = callback def on_connected_changed(self, value): + self.log.info("Connected" if value else "Disconnected") fire_and_forget(self.send({'Connected': value})) if self._on_connected_changed: self._on_connected_changed(value)