Have Sud report its own tick-counted elapsed time to clients

Window._elapsed_min() (client/brewpi_gui.py) reconstructed the dynamic
forecast's x-axis from wall-clock time times the server's nominal
configured sim_warp_factor. But that warp factor is only nominal -
real asyncio/Python scheduling overhead across the 7 concurrent tasks
means the actually-achieved speedup runs measurably below it (~80x
instead of 100x, confirmed by timing HoldRemaining countdowns against
real elapsed time), especially under heavy message/print load. Since
the GUI's reconstruction assumed a precise, constant mapping, the live
measured trace visibly drifted behind the forecast - most visible on
short, transition-dense test schedules where the timing slip is a
large fraction of the total duration.

components/sud.py: Sud now tracks 'elapsed' (tick-counted simulated
seconds since the run started, frozen while PAUSED/IDLE/DONE, reset on
start()) - the ground truth for run progress, immune to real-world
pacing jitter. tasks/sud.py broadcasts it as {'Sud': {'Elapsed': ...}}.

client/brewpi_gui.py: replaced sud_start_time/sud_paused_total/
sud_pause_started_at and all the wall-clock reconstruction in
_elapsed_min() with sud_elapsed_seconds, set directly from the
server's 'Elapsed' broadcasts - simpler too, since pause-freezing is
now handled server-side rather than needing separate client-side
bookkeeping.

Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01LhiQe64F74uHV8jzuoSa5K
This commit is contained in:
2026-06-22 11:21:39 +02:00
co-authored by Claude Sonnet 4.6
parent 76d3a6047c
commit 44b1b0c705
3 changed files with 39 additions and 34 deletions
+23 -34
View File
@@ -273,14 +273,15 @@ class Window(QtWidgets.QMainWindow, Ui_MainWindow):
# that arrives, or for a server that doesn't send it at all. # that arrives, or for a server that doesn't send it at all.
self.ambient_temp = None self.ambient_temp = None
self.warp_factor = 1.0 self.warp_factor = 1.0
# time.monotonic() of the last IDLE/DONE -> running transition, used # Elapsed simulated seconds of the current run, as reported by the
# to position the forecast plot's progress line; None while not # server (Sud's own tick-counted 'elapsed' - see components/sud.py) -
# running. sud_paused_total accumulates time spent PAUSED so the # None while not running. Used to position the forecast plot's
# progress line freezes during a pause instead of jumping ahead; # progress line; ground truth, not reconstructed from wall-clock
# sud_pause_started_at is when the current pause began, if any. # time, since the server's actual achieved speedup runs measurably
self.sud_start_time = None # below its nominal configured warp factor under real scheduling
self.sud_paused_total = 0.0 # load, which used to make the live trace visibly drift from the
self.sud_pause_started_at = None # forecast.
self.sud_elapsed_seconds = None
# Resolved schedule + live progress within it, kept around so the # Resolved schedule + live progress within it, kept around so the
# forecast plot can be dynamically re-anchored every tick instead of # forecast plot can be dynamically re-anchored every tick instead of
# only estimated once when the schedule was (re)loaded - see # only estimated once when the schedule was (re)loaded - see
@@ -428,16 +429,12 @@ class Window(QtWidgets.QMainWindow, Ui_MainWindow):
def _elapsed_min(self): def _elapsed_min(self):
"""Simulated-schedule minutes elapsed since the run started, or """Simulated-schedule minutes elapsed since the run started, or
None if no run is in progress. While paused, uses the moment the None if no run is in progress - straight from the server's own
pause began as "now" so it freezes instead of drifting ahead of tick-counted Sud.elapsed (see on_sud_changed()'s 'Elapsed'
actual progress.""" handling), already frozen while PAUSED there."""
if self.sud_start_time is None: if self.sud_elapsed_seconds is None:
return None return None
now = self.sud_pause_started_at if self.sud_pause_started_at is not None else time.monotonic() return self.sud_elapsed_seconds / 60.0
elapsed_real_s = now - self.sud_start_time - self.sud_paused_total
# The forecast's x-axis is simulated-schedule time; scale real
# elapsed time by the server's warp factor to match it.
return elapsed_real_s * self.warp_factor / 60.0
def on_plot_timer(self): def on_plot_timer(self):
self.plot.sample( self.plot.sample(
@@ -538,9 +535,7 @@ class Window(QtWidgets.QMainWindow, Ui_MainWindow):
self.lineEdit_ambient.clear() self.lineEdit_ambient.clear()
self.btn_pot_reset.setVisible(False) self.btn_pot_reset.setVisible(False)
self.warp_factor = 1.0 self.warp_factor = 1.0
self.sud_start_time = None self.sud_elapsed_seconds = None
self.sud_paused_total = 0.0
self.sud_pause_started_at = None
self.sud_name = '' self.sud_name = ''
self.sud_schedule = [] self.sud_schedule = []
self.sud_step_index = None self.sud_step_index = None
@@ -823,24 +818,16 @@ class Window(QtWidgets.QMainWindow, Ui_MainWindow):
prev_state = self.sud_state prev_state = self.sud_state
self.sud_state = msg['State'] self.sud_state = msg['State']
if self.sud_state == SUD_PAUSED_STATE and prev_state != SUD_PAUSED_STATE: if self.sud_state in SUD_RUNNING_STATES and self.sud_elapsed_seconds is None:
self.sud_pause_started_at = time.monotonic() self.sud_elapsed_seconds = 0.0
elif self.sud_state != SUD_PAUSED_STATE and prev_state == SUD_PAUSED_STATE:
self.sud_paused_total += time.monotonic() - self.sud_pause_started_at
self.sud_pause_started_at = None
if self.sud_state in SUD_RUNNING_STATES and self.sud_start_time is None:
self.sud_start_time = time.monotonic()
# Start the dynamic forecast's measured-history trace # Start the dynamic forecast's measured-history trace
# fresh for this run. # fresh for this run.
self.forecast_history = [] self.forecast_history = []
elif self.sud_state not in SUD_RUNNING_STATES and self.sud_state != SUD_PAUSED_STATE: elif self.sud_state not in SUD_RUNNING_STATES and self.sud_state != SUD_PAUSED_STATE:
was_running = self.sud_start_time is not None was_running = self.sud_elapsed_seconds is not None
self.sud_start_time = None self.sud_elapsed_seconds = None
self.sud_paused_total = 0.0
self.sud_pause_started_at = None
# on_plot_timer() only redraws the dynamic forecast while # on_plot_timer() only redraws the dynamic forecast while
# sud_start_time is set. # sud_elapsed_seconds is set.
if was_running: if was_running:
# A run just finished or was stopped - leave the # A run just finished or was stopped - leave the
# dynamic view's last frame (the actual measured # dynamic view's last frame (the actual measured
@@ -876,6 +863,8 @@ class Window(QtWidgets.QMainWindow, Ui_MainWindow):
elif "HoldRemaining" in key: elif "HoldRemaining" in key:
self.sud_hold_remaining = msg['HoldRemaining'] self.sud_hold_remaining = msg['HoldRemaining']
self.update_status_step_label() self.update_status_step_label()
elif "Elapsed" in key:
self.sud_elapsed_seconds = msg['Elapsed']
elif "RemainingForecast" in key: elif "RemainingForecast" in key:
forecast = msg['RemainingForecast'] forecast = msg['RemainingForecast']
# Anchor to elapsed_min as of receipt - close enough to # Anchor to elapsed_min as of receipt - close enough to
@@ -896,7 +885,7 @@ class Window(QtWidgets.QMainWindow, Ui_MainWindow):
# yet" preview show_schedule() drew; a run already in progress (or # yet" preview show_schedule() drew; a run already in progress (or
# one that's since finished) owns the plot via show_dynamic()/its # one that's since finished) owns the plot via show_dynamic()/its
# frozen last frame instead. # frozen last frame instead.
if self.sud_empty or self.sud_start_time is not None: if self.sud_empty or self.sud_elapsed_seconds is not None:
return return
t_min = [seconds / 60.0 for seconds in forecast['T']] t_min = [seconds / 60.0 for seconds in forecast['T']]
self.forecast_plot.show_precomputed_course(t_min, forecast['Theta'], self.sud_name) self.forecast_plot.show_precomputed_course(t_min, forecast['Theta'], self.sud_name)
+12
View File
@@ -106,6 +106,7 @@ class Sud(AttributeChange):
self.step = None self.step = None
self.user_message = None self.user_message = None
self._paused_from = None self._paused_from = None
self.elapsed = 0.0
def save(self): def save(self):
"""Returns the currently running sud.json document (EMPTY_SUD if """Returns the currently running sud.json document (EMPTY_SUD if
@@ -161,6 +162,7 @@ class Sud(AttributeChange):
if self.state not in (SudState.IDLE, SudState.DONE): if self.state not in (SudState.IDLE, SudState.DONE):
return return
self.index = -1 self.index = -1
self.elapsed = 0.0
self._advance() self._advance()
def pause(self): def pause(self):
@@ -195,6 +197,16 @@ class Sud(AttributeChange):
self._finish_step() self._finish_step()
def tick(self, dt): def tick(self, dt):
"""Advances the run by dt simulated seconds. 'elapsed' is the tick-
counted ground truth for how far the run has actually progressed -
clients used to reconstruct this themselves from wall-clock time
times the configured warp factor, but the warp factor is only
nominal (real asyncio/Python scheduling overhead means the actual
achieved speedup runs measurably below it, especially under heavy
message/print load), making that reconstruction drift from the
truth. Frozen while PAUSED/IDLE/DONE, same as hold_remaining."""
if self.state not in (SudState.IDLE, SudState.DONE, SudState.PAUSED):
self.elapsed += dt
if self.state == SudState.HOLDING: if self.state == SudState.HOLDING:
self.hold_remaining -= dt self.hold_remaining -= dt
if self.hold_remaining <= 0: if self.hold_remaining <= 0:
+4
View File
@@ -104,6 +104,9 @@ class SudTask(ATask):
def on_hold_remaining_changed(self, value): def on_hold_remaining_changed(self, value):
asyncio.create_task(self.send({'HoldRemaining': value})) asyncio.create_task(self.send({'HoldRemaining': value}))
def on_elapsed_changed(self, value):
asyncio.create_task(self.send({'Elapsed': value}))
async def send_forecast(self, doc): async def send_forecast(self, doc):
if self.forecast_estimator is None: if self.forecast_estimator is None:
return return
@@ -204,6 +207,7 @@ class SudTask(ATask):
self.sud.set_on_changed('state', self.on_state_changed) self.sud.set_on_changed('state', self.on_state_changed)
self.sud.set_on_changed('user_message', self.on_user_message_changed) self.sud.set_on_changed('user_message', self.on_user_message_changed)
self.sud.set_on_changed('hold_remaining', ChangedFloat(self.on_hold_remaining_changed, prec=0).set) self.sud.set_on_changed('hold_remaining', ChangedFloat(self.on_hold_remaining_changed, prec=0).set)
self.sud.set_on_changed('elapsed', ChangedFloat(self.on_elapsed_changed, prec=1).set)
asyncio.create_task(self.send({'Name': self.sud.name, 'Description': self.sud.description})) asyncio.create_task(self.send({'Name': self.sud.name, 'Description': self.sud.description}))