import asyncio import json import os import time from tasks import ATask from components import APid, AHeater class ServerLogTask(ATask): """Continuously records temp/power samples from server start to shutdown. Writes a single log_{date_time}.json on close() in the same format as SudLogTask (Name/Samples) so analyze_log.py and replay_sim.py can consume it directly. Unlike SudLogTask, which only records during an active Sud run, this log covers the full server session regardless of Sud state — useful for verifying controller and heater behaviour outside of a scheduled brew.""" def __init__(self, tc: APid, heater: AHeater, heater_task, interval, path='./logs', config=None, dt=None, log_interval=None, sim_warp_factor=None): ATask.__init__(self, interval) self.tc = tc self.heater = heater self.heater_task = heater_task self.path = path self.config = config self.dt = dt self.log_interval = log_interval self.sim_warp_factor = sim_warp_factor self._samples = [] self._param_events = [] self._elapsed_total = 0.0 self._run_id = time.strftime("%Y%m%dT%H%M%S", time.localtime()) self._last_write = time.monotonic() def log_plant_params(self, elapsed, params): self._param_events.append({'t': elapsed, 'params': params}) async def on_process(self): while True: if self._should_sample(): self._samples.append(self._take_sample()) # Periodically checkpoints to disk (same file, overwritten whole # each time - see write()) so a hard crash/power loss only loses # up to log_interval seconds, not the whole session/run. This # checkpoint cadence is deliberately real (wall-clock) time, # unlike _elapsed() below - it's bounding real data-loss risk, # not tracking brew progress. now = time.monotonic() # Gated on _should_sample(): for SudLogTask, a completed run's # stop_run() already wrote the correct final state and cleared # _param_events for the *next* run - an unguarded checkpoint # here would otherwise fire on the very next iteration (once # log_interval real seconds have passed since the last one, # regardless of the run having ended in between) and clobber # that already-correct file with _samples unchanged but # _param_events now empty. if self.log_interval and self._should_sample() and now - self._last_write >= self.log_interval: self.write() self._last_write = now await asyncio.sleep(self.interval) self._elapsed_total += self.dt def _should_sample(self): return True def _elapsed(self): """Simulated seconds elapsed since this task started sampling - tick-counted (advances by self.dt once per on_process() iteration), never derived from wall-clock time: under sim_warp_factor, real and simulated time diverge (see components/sud.py's Sud.elapsed, and the README's "Forecast vs. actual duration" section, for the same reasoning), so a wall-clock 't' would desync from the forecast's own tick-counted timeline it's meant to be compared against.""" return self._elapsed_total def _take_sample(self): power_set = max(self.heater_task.power_soll, self.heater_task.power_actor) return { 't': self._elapsed(), 'timestamp': time.time(), 'temp_ist': self.tc.theta_ist, 'temp_soll': self.tc.theta_soll_set, 'rate_ist': self.tc.heatrate_ist, 'rate_soll': self.tc.heatrate_soll, 'power_set': power_set, 'power_eff': self.heater.power_eff, } def _filename(self): return 'log_{}.json'.format(self._run_id) def _latest_filename(self): """Fixed (no-date) name written alongside the dated one on every write() - always overwritten, so a dashboard/tail-style consumer can point at one unchanging path instead of tracking the current run's own timestamped filename.""" return 'log_latest.json' def _extra_log_data(self): """Hook for subclasses (SudLogTask) to contribute additional keys to write()'s output - see there.""" return {} def _log_name(self): """Hook for subclasses (SudLogTask) - a server-session log covers the whole process lifetime rather than one named run, so it has none of its own.""" return '' def write(self): if not self._samples: return os.makedirs(self.path, exist_ok=True) filename = self._filename() log_data = {'Name': self._log_name()} if self.dt is not None: log_data['dt'] = self.dt if self.sim_warp_factor is not None: log_data['SimWarpFactor'] = self.sim_warp_factor if self.config is not None: log_data['Config'] = self.config # Queried live from the connected device rather than reconstructed # offline (utils/analyze_log.py has no hardware to ask) - needed to # reproduce this run's SudForecastEstimator (see components/ # sud_forecast.py) for a post-hoc forecast-vs-actual comparison. log_data['HeaterPowers'] = self.heater.get_powers() if self._param_events: log_data['PlantParams'] = self._param_events log_data.update(self._extra_log_data()) log_data['Samples'] = self._samples # Written to both the dated filename (this run/session's own # permanent record) and a fixed, always-overwritten one (see # _latest_filename()) - same content, so a consumer wanting # "whatever's most current" never has to track the dated name. for name in (filename, self._latest_filename()): with open(os.path.join(self.path, name), 'w') as f: json.dump(log_data, f, indent='\t') print('Server log: wrote {} samples to {}'.format(len(self._samples), filename))