test_scheduler_chamber_soak.py 20 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514
  1. """Tests for chamber-soak history tracking and smart soak-time reduction.
  2. `_chamber_soak_remaining()` scans a per-printer deque of
  3. (monotonic_timestamp, celsius) samples and returns how many soak seconds
  4. are still needed, crediting time the chamber has already spent above the
  5. target threshold. Real samples arrive every 3–30 s while a printer is
  6. connected; tests use `_dense_history` to model that cadence, or `_history`
  7. (sparse) when specifically exercising gap-detection behaviour.
  8. Key invariants:
  9. - Empty history → full soak (conservative)
  10. - Chamber never dipped, contiguous run < soak → credit the run's span
  11. - Chamber never dipped, contiguous run ≥ soak → skip (return 0)
  12. - Chamber dipped → credit only time since last below-threshold sample
  13. - Chamber currently below → full soak (time_above ≈ 0)
  14. - Gap in samples larger than the cadence threshold → credit only the
  15. last contiguous run (disconnect must not be counted as time at temp)
  16. `_sample_chamber_temps()` records one sample per connected printer per
  17. tick, prunes entries older than the 2 h TTL, and evicts per-printer state
  18. whose printer_id disappeared from the manager (printer deleted).
  19. """
  20. from collections import deque
  21. from types import SimpleNamespace
  22. from unittest.mock import patch
  23. import pytest
  24. from backend.app.services.print_scheduler import (
  25. _CHAMBER_HISTORY_TTL_SECONDS,
  26. _CHAMBER_SAMPLE_MAX_GAP_SECONDS,
  27. PrintScheduler,
  28. )
  29. SOAK = 1800 # seconds (30 min, the typical configured value)
  30. TARGET = 50.0 # °C
  31. PRINTER_ID = 1
  32. NOW = 10_000.0
  33. @pytest.fixture
  34. def scheduler():
  35. return PrintScheduler()
  36. def _history(*entries):
  37. """Build a deque of (monotonic_ts, celsius) from sparse offset-celsius pairs.
  38. Offsets are relative to NOW (negative = seconds before now). Use this
  39. directly when the test needs an explicit gap between samples
  40. (disconnect/reconnect scenarios). Otherwise prefer `_dense_history`.
  41. """
  42. d = deque()
  43. for offset, temp in entries:
  44. d.append((NOW + offset, float(temp)))
  45. return d, NOW
  46. def _dense_history(*entries, interval=30):
  47. """Build a deque with samples every `interval` seconds between entries,
  48. step-filled with the value of the previous entry. Mirrors the real
  49. sampling cadence, so the contiguity guard sees an unbroken run.
  50. """
  51. d = deque()
  52. if not entries:
  53. return d, NOW
  54. sorted_entries = sorted(entries, key=lambda e: e[0])
  55. prev_offset, prev_temp = sorted_entries[0]
  56. d.append((NOW + prev_offset, float(prev_temp)))
  57. for offset, temp in sorted_entries[1:]:
  58. cur = prev_offset + interval
  59. while cur < offset:
  60. d.append((NOW + cur, float(prev_temp)))
  61. cur += interval
  62. d.append((NOW + offset, float(temp)))
  63. prev_offset, prev_temp = offset, temp
  64. return d, NOW
  65. # ---------------------------------------------------------------------------
  66. # No history
  67. # ---------------------------------------------------------------------------
  68. def test_empty_history_returns_full_soak(scheduler):
  69. """No samples at all → conservative: return configured soak in full."""
  70. with patch("backend.app.services.print_scheduler.time") as t:
  71. t.monotonic.return_value = NOW
  72. result = scheduler._chamber_soak_remaining(PRINTER_ID, TARGET, SOAK)
  73. assert result == SOAK
  74. # ---------------------------------------------------------------------------
  75. # Chamber never dropped below threshold — contiguous run credit
  76. # ---------------------------------------------------------------------------
  77. def test_history_shorter_than_soak_credits_span(scheduler):
  78. """Chamber above target for 600 s of contiguous samples.
  79. Old behaviour returned full soak (wrong). New behaviour credits the
  80. 600 s we have evidence for → remaining = 1800 - 600 = 1200 s.
  81. """
  82. hist, now = _dense_history((-600, 55), (0, 53))
  83. scheduler._chamber_history[PRINTER_ID] = hist
  84. with patch("backend.app.services.print_scheduler.time") as t:
  85. t.monotonic.return_value = now
  86. result = scheduler._chamber_soak_remaining(PRINTER_ID, TARGET, SOAK)
  87. assert result == SOAK - 600
  88. def test_history_equal_to_soak_returns_zero(scheduler):
  89. """Chamber above target for exactly soak_seconds → remaining = 0."""
  90. hist, now = _dense_history((-SOAK, 55), (0, 52))
  91. scheduler._chamber_history[PRINTER_ID] = hist
  92. with patch("backend.app.services.print_scheduler.time") as t:
  93. t.monotonic.return_value = now
  94. result = scheduler._chamber_soak_remaining(PRINTER_ID, TARGET, SOAK)
  95. assert result == 0
  96. def test_history_longer_than_soak_returns_zero(scheduler):
  97. """Chamber above target for longer than soak_seconds → skip entirely."""
  98. hist, now = _dense_history((-3600, 56), (0, 52))
  99. scheduler._chamber_history[PRINTER_ID] = hist
  100. with patch("backend.app.services.print_scheduler.time") as t:
  101. t.monotonic.return_value = now
  102. result = scheduler._chamber_soak_remaining(PRINTER_ID, TARGET, SOAK)
  103. assert result == 0
  104. # ---------------------------------------------------------------------------
  105. # Chamber dipped below threshold at some point
  106. # ---------------------------------------------------------------------------
  107. def test_recent_dip_credits_only_time_since_dip(scheduler):
  108. """A real cooldown (10 min below threshold) restarts the credit at its end.
  109. Samples run at the real 30 s cadence: hot until -1500 s, below threshold
  110. from -1500 s to -900 s, hot again from -870 s. Credit starts at the last
  111. below-threshold sample (-900 s), so remaining = 1800 - 900 = 900.
  112. """
  113. hist, now = _dense_history((-3000, 55), (-1500, 44), (-870, 55), (0, 52))
  114. scheduler._chamber_history[PRINTER_ID] = hist
  115. with patch("backend.app.services.print_scheduler.time") as t:
  116. t.monotonic.return_value = now
  117. result = scheduler._chamber_soak_remaining(PRINTER_ID, TARGET, SOAK)
  118. assert result == SOAK - 900
  119. def test_dip_long_enough_ago_returns_zero(scheduler):
  120. """A real cooldown that ended longer ago than the soak → fully credited → 0."""
  121. hist, now = _dense_history((-4000, 55), (-2600, 44), (-1970, 55), (0, 52))
  122. scheduler._chamber_history[PRINTER_ID] = hist
  123. with patch("backend.app.services.print_scheduler.time") as t:
  124. t.monotonic.return_value = now
  125. result = scheduler._chamber_soak_remaining(PRINTER_ID, TARGET, SOAK)
  126. assert result == 0
  127. # ---------------------------------------------------------------------------
  128. # Dip debounce: brief sub-threshold readings are artifacts, not lost soak
  129. # ---------------------------------------------------------------------------
  130. def test_brief_dip_does_not_reset_credit(scheduler):
  131. """A single stray low sample must not discard hours of accumulated soak.
  132. The chamber cannot physically lose and regain 8°C in one sampling interval
  133. (measured: ~0.2 C/min), so this is a sensor artifact. Crediting from before
  134. the blip leaves the full hour, i.e. no soak needed.
  135. """
  136. hist, now = _dense_history((-3600, 55), (-600, 47), (-540, 55), (0, 55))
  137. scheduler._chamber_history[PRINTER_ID] = hist
  138. with patch("backend.app.services.print_scheduler.time") as t:
  139. t.monotonic.return_value = now
  140. result = scheduler._chamber_soak_remaining(PRINTER_ID, TARGET, SOAK)
  141. assert result == 0
  142. def test_four_minute_door_open_dip_does_not_reset_credit(scheduler):
  143. """The real-world case: opening the door to clear the plate.
  144. Modelled on an excursion actually recorded on an X1C — roughly four minutes
  145. below threshold, bottoming one degree under it, then straight back. That is
  146. air exchange, not the chamber mass cooling, so the soak still counts.
  147. """
  148. hist, now = _dense_history((-3600, 55), (-900, 47), (-660, 55), (0, 55))
  149. scheduler._chamber_history[PRINTER_ID] = hist
  150. with patch("backend.app.services.print_scheduler.time") as t:
  151. t.monotonic.return_value = now
  152. result = scheduler._chamber_soak_remaining(PRINTER_ID, TARGET, SOAK)
  153. assert result == 0
  154. def test_dip_past_grace_period_does_reset_credit(scheduler):
  155. """An excursion longer than the grace is real cooling and does reset it.
  156. Guards the other side of the debounce: 25 minutes below threshold is far
  157. slower than any artifact and well within the measured cooling rate, so the
  158. credit restarts at the end of the dip (-1530 s) → 1800 - 1530 = 270.
  159. """
  160. hist, now = _dense_history((-5000, 55), (-3000, 45), (-1500, 55), (0, 55))
  161. scheduler._chamber_history[PRINTER_ID] = hist
  162. with patch("backend.app.services.print_scheduler.time") as t:
  163. t.monotonic.return_value = now
  164. result = scheduler._chamber_soak_remaining(PRINTER_ID, TARGET, SOAK)
  165. assert result == SOAK - 1530
  166. # ---------------------------------------------------------------------------
  167. # Freshness: an old history is not evidence about the chamber right now
  168. # ---------------------------------------------------------------------------
  169. def test_stale_history_requires_full_soak(scheduler):
  170. """Hot history whose newest sample predates the max gap → full soak.
  171. The printer stopped reporting; at the measured cooling rate the chamber can
  172. cross the threshold inside such a window, so nothing may be credited.
  173. """
  174. hist, _ = _dense_history((-7200, 55), (-1800, 55))
  175. scheduler._chamber_history[PRINTER_ID] = hist
  176. with patch("backend.app.services.print_scheduler.time") as t:
  177. t.monotonic.return_value = NOW
  178. result = scheduler._chamber_soak_remaining(PRINTER_ID, TARGET, SOAK)
  179. assert result == SOAK
  180. def test_fresh_history_within_max_gap_is_credited(scheduler):
  181. """Boundary partner: a newest sample inside the max gap still counts."""
  182. hist, _ = _dense_history((-7200, 55), (-30, 55))
  183. scheduler._chamber_history[PRINTER_ID] = hist
  184. with patch("backend.app.services.print_scheduler.time") as t:
  185. t.monotonic.return_value = NOW
  186. result = scheduler._chamber_soak_remaining(PRINTER_ID, TARGET, SOAK)
  187. assert result == 0
  188. def test_currently_below_threshold_returns_full_soak(scheduler):
  189. """Most recent sample is below threshold → time_above ≈ 0 → full soak."""
  190. hist, now = _history(
  191. (-600, 55),
  192. (-300, 52),
  193. (0, 45), # BELOW threshold right now
  194. )
  195. scheduler._chamber_history[PRINTER_ID] = hist
  196. with patch("backend.app.services.print_scheduler.time") as t:
  197. t.monotonic.return_value = now
  198. result = scheduler._chamber_soak_remaining(PRINTER_ID, TARGET, SOAK)
  199. assert result == SOAK
  200. # ---------------------------------------------------------------------------
  201. # Contiguity / gap handling in the no-dip branch
  202. # ---------------------------------------------------------------------------
  203. def test_disconnect_gap_credits_only_last_contiguous_run(scheduler):
  204. """Chamber above threshold both before AND after a big gap in samples.
  205. Simulates a printer that was hot, disconnected for 30 min, and came back
  206. still hot. We cannot claim it was at temperature during the disconnect —
  207. only the most recent contiguous run counts. Credit = 600 s (post-gap
  208. run), remaining = 1800 - 600 = 1200.
  209. """
  210. pre_gap, _ = _dense_history((-3000, 55), (-2000, 55))
  211. post_gap, now = _dense_history((-600, 55), (0, 55))
  212. hist = deque(list(pre_gap) + list(post_gap))
  213. scheduler._chamber_history[PRINTER_ID] = hist
  214. with patch("backend.app.services.print_scheduler.time") as t:
  215. t.monotonic.return_value = now
  216. result = scheduler._chamber_soak_remaining(PRINTER_ID, TARGET, SOAK)
  217. assert result == SOAK - 600
  218. def test_sample_gap_at_cadence_threshold_still_contiguous(scheduler):
  219. """A gap exactly at the max-gap threshold does NOT break contiguity.
  220. The check is strictly greater-than, so a gap == threshold still credits
  221. across it. Guards against off-by-one drift in the contiguity heuristic.
  222. """
  223. hist, now = _history(
  224. (-1800, 55),
  225. (-1800 + int(_CHAMBER_SAMPLE_MAX_GAP_SECONDS), 55), # gap = threshold exactly
  226. (0, 55),
  227. )
  228. # Fill densely from the second entry onwards so only the first-to-second
  229. # gap is at the threshold.
  230. dense_tail, _ = _dense_history(
  231. (-1800 + int(_CHAMBER_SAMPLE_MAX_GAP_SECONDS), 55),
  232. (0, 55),
  233. )
  234. hist = deque([hist[0]] + list(dense_tail))
  235. scheduler._chamber_history[PRINTER_ID] = hist
  236. with patch("backend.app.services.print_scheduler.time") as t:
  237. t.monotonic.return_value = now
  238. result = scheduler._chamber_soak_remaining(PRINTER_ID, TARGET, SOAK)
  239. assert result == 0
  240. # ---------------------------------------------------------------------------
  241. # Tolerance boundary
  242. # ---------------------------------------------------------------------------
  243. def test_tolerance_boundary_above_counts_as_above(scheduler):
  244. """Sample at target - tolerance + 0.1 is above threshold → credit."""
  245. threshold_plus = TARGET - 2.0 + 0.1 # 48.1°C — just above threshold
  246. hist, now = _dense_history((-SOAK, threshold_plus), (0, threshold_plus))
  247. scheduler._chamber_history[PRINTER_ID] = hist
  248. with patch("backend.app.services.print_scheduler.time") as t:
  249. t.monotonic.return_value = now
  250. result = scheduler._chamber_soak_remaining(PRINTER_ID, TARGET, SOAK)
  251. assert result == 0
  252. def test_tolerance_boundary_at_threshold_counts_as_above(scheduler):
  253. """Sample exactly AT target - tolerance is NOT below (strictly less-than).
  254. Three contiguous samples 30 s apart: 55, 48.0, 55. The middle sample sits
  255. exactly at the threshold (48.0). If the at-threshold check counted as
  256. 'below', last_below_ts would fire on the middle sample and remaining
  257. would be SOAK - 30 = 1770. Because the check is strict ``temp < threshold``
  258. (and 48.0 < 48.0 is False), no dip is found — the whole 60 s contiguous
  259. span is credited and remaining = SOAK - 60 = 1740.
  260. Distinguishing the two branches is the point: the OLD test compared
  261. against 0 no matter which branch fired.
  262. """
  263. at_threshold = TARGET - 2.0 # 48.0°C
  264. hist, now = _history((-60, 55), (-30, at_threshold), (0, 55))
  265. scheduler._chamber_history[PRINTER_ID] = hist
  266. with patch("backend.app.services.print_scheduler.time") as t:
  267. t.monotonic.return_value = now
  268. result = scheduler._chamber_soak_remaining(PRINTER_ID, TARGET, SOAK)
  269. assert result == SOAK - 60
  270. # ---------------------------------------------------------------------------
  271. # Result is always non-negative
  272. # ---------------------------------------------------------------------------
  273. def test_result_never_negative(scheduler):
  274. """Even if the contiguous run spans many times the soak duration, floors at 0."""
  275. hist, now = _dense_history((-7200, 55), (0, 52))
  276. scheduler._chamber_history[PRINTER_ID] = hist
  277. with patch("backend.app.services.print_scheduler.time") as t:
  278. t.monotonic.return_value = now
  279. result = scheduler._chamber_soak_remaining(PRINTER_ID, TARGET, SOAK)
  280. assert result == 0
  281. # ---------------------------------------------------------------------------
  282. # _sample_chamber_temps: recording, TTL, gating, eviction
  283. # ---------------------------------------------------------------------------
  284. def _status(*, connected=True, chamber=None, bed=None):
  285. """Build a PrinterStatus-shaped namespace. `chamber=None` → key absent."""
  286. temps: dict = {}
  287. if chamber is not None:
  288. temps["chamber"] = chamber
  289. if bed is not None:
  290. temps["bed"] = bed
  291. return SimpleNamespace(connected=connected, temperatures=temps)
  292. def test_sample_chamber_temps_appends_current_reading(scheduler):
  293. """Each tick appends one (now, chamber_temp) sample per connected printer."""
  294. with (
  295. patch("backend.app.services.print_scheduler.time") as t,
  296. patch("backend.app.services.print_scheduler.printer_manager") as pm,
  297. ):
  298. t.monotonic.return_value = NOW
  299. pm.get_all_statuses.return_value = {PRINTER_ID: _status(chamber=52.5)}
  300. scheduler._sample_chamber_temps()
  301. hist = scheduler._chamber_history[PRINTER_ID]
  302. assert list(hist) == [(NOW, 52.5)]
  303. def test_sample_chamber_temps_prunes_entries_beyond_ttl(scheduler):
  304. """Samples older than _CHAMBER_HISTORY_TTL_SECONDS are popped from the deque."""
  305. old = NOW - _CHAMBER_HISTORY_TTL_SECONDS - 100
  306. recent = NOW - 30
  307. scheduler._chamber_history[PRINTER_ID] = deque([(old, 55.0), (recent, 55.0)])
  308. with (
  309. patch("backend.app.services.print_scheduler.time") as t,
  310. patch("backend.app.services.print_scheduler.printer_manager") as pm,
  311. ):
  312. t.monotonic.return_value = NOW
  313. pm.get_all_statuses.return_value = {PRINTER_ID: _status(chamber=55.0)}
  314. scheduler._sample_chamber_temps()
  315. ts_values = [entry[0] for entry in scheduler._chamber_history[PRINTER_ID]]
  316. assert old not in ts_values
  317. assert recent in ts_values
  318. def test_sample_chamber_temps_skips_absent_chamber_key(scheduler):
  319. """No 'chamber' key (e.g. printer without chamber sensor) → no sample recorded."""
  320. with (
  321. patch("backend.app.services.print_scheduler.time") as t,
  322. patch("backend.app.services.print_scheduler.printer_manager") as pm,
  323. ):
  324. t.monotonic.return_value = NOW
  325. pm.get_all_statuses.return_value = {PRINTER_ID: _status(bed=60.0)} # no chamber
  326. scheduler._sample_chamber_temps()
  327. assert PRINTER_ID not in scheduler._chamber_history
  328. def test_sample_chamber_temps_skips_disconnected_printer(scheduler):
  329. """A registered but disconnected printer keeps stale temps → don't sample it."""
  330. with (
  331. patch("backend.app.services.print_scheduler.time") as t,
  332. patch("backend.app.services.print_scheduler.printer_manager") as pm,
  333. ):
  334. t.monotonic.return_value = NOW
  335. pm.get_all_statuses.return_value = {PRINTER_ID: _status(connected=False, chamber=55.0)}
  336. scheduler._sample_chamber_temps()
  337. assert PRINTER_ID not in scheduler._chamber_history
  338. def test_sample_chamber_temps_evicts_history_for_removed_printer(scheduler):
  339. """A printer_id present in _chamber_history but not in the manager → evicted."""
  340. scheduler._chamber_history[99] = deque([(NOW - 100, 55.0)])
  341. scheduler._chamber_history[PRINTER_ID] = deque([(NOW - 100, 55.0)])
  342. with (
  343. patch("backend.app.services.print_scheduler.time") as t,
  344. patch("backend.app.services.print_scheduler.printer_manager") as pm,
  345. ):
  346. t.monotonic.return_value = NOW
  347. pm.get_all_statuses.return_value = {PRINTER_ID: _status(chamber=55.0)}
  348. scheduler._sample_chamber_temps()
  349. assert 99 not in scheduler._chamber_history
  350. assert PRINTER_ID in scheduler._chamber_history
  351. def test_sample_chamber_temps_evicts_keep_warm_state_for_removed_printer(scheduler):
  352. """A printer_id in _keep_warm but not in the manager → evicted."""
  353. from backend.app.services.print_scheduler import _KeepWarmEntry
  354. scheduler._keep_warm[99] = _KeepWarmEntry(started=NOW - 100, held_target=100)
  355. scheduler._keep_warm[PRINTER_ID] = _KeepWarmEntry(started=NOW - 100, held_target=100)
  356. with (
  357. patch("backend.app.services.print_scheduler.time") as t,
  358. patch("backend.app.services.print_scheduler.printer_manager") as pm,
  359. ):
  360. t.monotonic.return_value = NOW
  361. pm.get_all_statuses.return_value = {PRINTER_ID: _status(chamber=55.0)}
  362. scheduler._sample_chamber_temps()
  363. assert 99 not in scheduler._keep_warm
  364. assert PRINTER_ID in scheduler._keep_warm
  365. def test_sample_chamber_temps_none_status_ignored(scheduler):
  366. """get_all_statuses() can return None entries — those must not crash sampling.
  367. The None-check must run BEFORE `status.connected` is dereferenced, or an
  368. unregistered / mid-shutdown entry will AttributeError the whole tick.
  369. """
  370. with (
  371. patch("backend.app.services.print_scheduler.time") as t,
  372. patch("backend.app.services.print_scheduler.printer_manager") as pm,
  373. ):
  374. t.monotonic.return_value = NOW
  375. pm.get_all_statuses.return_value = {2: None, PRINTER_ID: _status(chamber=55.0)}
  376. scheduler._sample_chamber_temps()
  377. assert 2 not in scheduler._chamber_history
  378. assert PRINTER_ID in scheduler._chamber_history