fix(agent): stop reconnects and restarts erasing device truth from the status topic - #13
Conversation
…e status topic The retained status carried nulls for serial, firmware, battery_pct, voltage_v and media_ok almost all of the time, so InvenTree's Machines page read "CONNECTED — media unreported" for a printer the agent had fully identified on its last job. Two causes, and the second is the one that actually bites. _on_connect published a *hardcoded* bare PrinterStatus, retained. That fires on every reconnect, not only the first connect, and paho reconnects silently -- the broker's Istio route caps at a 24h timeout and flaps besides -- so it ran several times a day. It was not merely uninformative, it was lossy: it overwrote a retained message that had been correct a moment earlier, and the printer is asleep between jobs and cannot be asked again. Evidence was an agent 25h up with NRestarts=0 and every device field null. The rarer cause is the one the issue was filed about: a fresh process knew nothing at all, because the device fields lived in six attributes on PrintWorker that were only ever filled inside a send. Both are the same missing idea -- nowhere to keep what the printer said. DeviceSnapshot is that place, persisted to the spool DB after every capture and read back at startup. The MQTT source now remembers the last retained status it published, seeded from the spool, and republishes *that* on connect. The will and the shutdown notice carry it too: losing the link is news about reachability, not grounds for forgetting the serial. Remembered truth published as though it were live is its own kind of lie, so PrinterStatus gains device_seen_at. An absolute UTC instant rather than an age, because the message is retained -- an age is computed once and then sits on the broker getting wronger. It only advances when the printer actually reported something, so a connection that answered nothing cannot launder three-day-old media state into looking current. device.probe_on_start (on by default) surveys the printer once at startup, so an agent that comes up next to an awake printer publishes live truth immediately instead of waiting for the next job. It cannot wake a sleeping unit -- AUTO_POWER_TIME really does power the radio down and only the button brings it back -- so a miss costs one connect timeout and the stored snapshot is published unchanged. It runs on the print loop and only at startup, never from on_connect: that callback is paho's network thread, and probing from it would touch the printer concurrently with a print, which is exactly what the single-threaded loop exists to prevent. Collecting the snapshot also removed the duplicated PrinterStatus construction between worker.py and source_mqtt.py, which is why the two could disagree about what the topic should say in the first place. tests/test_source_mqtt.py is new -- that module had no coverage, which is how a hardcoded blank status survived in the one callback that runs most often. The README still claimed "there is no read channel" and that low battery was undetectable. That was falsified by #9; corrected here. Closes #12
|
Consumer half is up: sengine-cloud/inventree-label-dispatch#7 renders |
|
Thanks — acted on the LWT point, and it turned out to be partly fixable rather than only documentable. Correct that the will is frozen for the life of a connection: it rides in the CONNECT packet and the broker holds it, so nothing changes what fires if that session drops. But paho rebuilds CONNECT from the same The residual constraint is in the PR description now, along with the two cosmetics: 265 tests green, ruff clean. |
… forever Review flagged that the will goes stale after start(): paho bakes it into the CONNECT packet, so the payload the broker holds is fixed for the life of a connection and an ungraceful drop weeks in would have published boot-time device truth. Half of that is unavoidable and stays true -- nothing can change what fires if *this* connection dies. The other half is not: paho rebuilds CONNECT from the same _will_* fields on every automatic reconnect (verified in 2.1.0 -- will_set has no connected-state guard, and _send_connect reads _will_payload at packet-build time). Re-arming from _on_connect therefore bounds the staleness by the reconnect interval, a few hours here, instead of by the process lifetime. Armed from paho's network thread, which is also the thread that builds the packet, so the topic and payload can never come from different arming passes.
Review on the consumer PR pointed out that a fault learned mid-session cannot reach the will -- the broker holds it from CONNECT -- so an agent killed after a media fault publishes the older, healthier reading over the newer one. Nothing prevents that, and neither suggested remedy helps: on_disconnect fires with no connection to publish on, and a SIGKILL runs no callback at all. What bounds it is recovery. The unit is Restart=always with RestartSec=5, and a restarted agent seeds _last_status from the spool -- which does hold the fault -- and republishes on connect, so the stale row is seconds wide rather than indefinite. That property was load-bearing in the argument and untested, which is a bad combination. Now asserted end to end: arm a healthy will, learn a fault mid-session, restart on the same spool, and check the republished status carries the fault and a device_seen_at strictly newer than the will's.
…nside it (#8) Follow-up to #7, which merged before these review points were addressed. Same three changes, rebased onto the merged main. ## The window the age cannot cover Review raised a case this module cannot defend against, and it is worth writing down rather than leaving to be rediscovered. The agent's MQTT will is fixed when its connection opens and the broker holds it, so a fault learned *during* that session never reaches it. Agent connects while the tape is fine → a print an hour later finds the tape gone and correctly publishes `media_ok: false` → agent is killed → the broker publishes the older, *healthier* reading over the newer one, and this page renders `DISCONNECTED` with a stale-healthy detail line. Nothing here can detect it: retained MQTT v3.1.1 messages carry no publish timestamp. So the README note says where the recovery actually comes from rather than pretending to a fix — the agent restarts (`Restart=always`, `RestartSec=5`), seeds from its spool, which *does* hold the fault, and republishes. Seconds wide, not indefinite. Worth being precise about what does **not** close it, since both were suggested: `on_disconnect` fires with no connection to publish on, and a SIGKILL runs no callback at all. Re-arming the will on reconnect (done in sengine-cloud/labelfab#13) bounds it by the reconnect interval rather than the process lifetime, but cannot touch a live session. The recovery path is now pinned by a test upstream rather than left as an argument. ## Two nits `_ago`'s `seen` is annotated `object`, deliberately not `str | None` — it comes out of `json.loads` on a payload this process did not produce and can be any JSON type, so a narrow annotation would move the lie into the signature rather than remove it. Under 10 seconds renders `seen just now` instead of `seen 0s ago`. That is the common case, since the page is usually looked at right after printing something. ## Verified 49 tests on 3.12, 37 on a real 3.9.25 in Docker, ruff clean.
A minor rather than a patch: the retained PrinterStatus gains device_seen_at, and device.probe_on_start is new behaviour that ships on. The status topic no longer loses what the printer said. A broker reconnect used to publish a hardcoded bare status over it, retained, several times a day; a restart had nothing to publish at all. Device truth is now persisted in the spool and republished, stamped with when it was actually observed (#12, #13).
Closes #12.
What was happening
Two causes behind one symptom, and the one in the issue comment is the one that actually bites.
_on_connectpublished a hardcoded barePrinterStatus, retained. That fires on every reconnect, not just the first connect, and paho reconnects silently — the broker's Istio route caps at a 24h timeout and flaps besides — so it ran several times a day. It was not merely uninformative, it was lossy: it overwrote a retained message that had been correct a moment earlier, and the printer sleeps between jobs so nothing could put it back. Hence an agent 25h up,NRestarts=0, every device fieldnull.The rarer cause is the one the issue was filed about: a fresh process knew nothing at all, because the device fields lived in six attributes on
PrintWorkerthat were only ever filled inside a send.Both are the same missing idea — nowhere to keep what the printer said.
What this does
DeviceSnapshot(agent/device_state.py) is that place, persisted to the spool DB after every capture and read back at startup. The MQTT source remembers the last retained status it published, seeded from the spool, and republishes that on connect. The will and the shutdown notice carry it too: losing the link is news about reachability, not grounds for forgetting the serial.device_seen_atis new onPrinterStatus. Remembered truth published as though it were live is its own kind of lie — the same failure the tri-statemedia_okexists to avoid, one layer along. An absolute UTC instant rather than an age, because the message is retained: an age is computed once and then sits on the broker getting wronger. It only advances when the printer actually reported something, so a connection that answered nothing cannot launder three-day-old media state into looking current.{"v":1,"printer_id":"d30-workshop","state":"idle","model":"phomemo-d30", "serial":"Q223P4C31420105","firmware":"2.1.2","battery_pct":100,"voltage_v":4.17, "media_ok":true,"tape_width_mm":15.0,"pending_labels":0,"error":null, "device_seen_at":"2026-08-02T09:14:03Z"}contracts/job-v1.schema.jsonis generated fromPrintJobonly, so the schema gate is untouched, and the InvenTree driver reads the payload with.get(), so the new field is backwards compatible.device.probe_on_start(on by default) surveys the printer once at startup, so an agent coming up next to an awake printer publishes live truth immediately rather than waiting for the next job. This cannot wake a sleeping unit —AUTO_POWER_TIMEreally does power the radio down and only the button brings it back — so a miss costs one connect timeout and the stored snapshot is published unchanged.It runs on the print loop and only at startup, deliberately not from
on_connect. That callback is paho's network thread, so probing there would touch the printer concurrently with a print — the one thing the single-threaded loop exists to prevent — and it would fire on every broker reconnect, several times a day, over a link that says nothing about the printer.One behaviour change worth flagging: with the probe on, an agent configured without
device.macnow fails at startup rather than at first print. That config could never have printed anyway, so failing where systemd will show it seems the better of the two.Verified
Full suite green (264 passed), ruff clean, schema in sync. End to end without hardware or a broker — print one job, drop the process, bring a new
Spool+MqttSourceup on the same DB, fire_on_connect:against
CONNECTED — media unreportedtoday.tests/test_source_mqtt.pyis new. That module had no coverage at all, which is how a hardcoded blank status survived in the one callback that runs most often.Also
The README still claimed "There is no read channel… low battery [is] undetectable". That was falsified by #9 and this change makes it actively misleading, so it is corrected here.
HARDWARE-NOTES.mdwas already right.Consumer-side follow-up in sengine-cloud/inventree-label-dispatch renders the age on the Machines page, so remembered truth is not shown as live there either.
What the will can and cannot promise
Raised in review, and worth having written down because the code reads as if the will is always current and it is not.
The will rides in the CONNECT packet, so the broker holds one fixed payload for the life of a connection. Nothing the agent does while connected can change what fires if that connection dies — a mid-session drop publishes whatever was armed when the session opened.
That is only half the story, though. paho rebuilds CONNECT from the same
_will_*fields on every automatic reconnect —will_sethas no connected-state guard and_send_connectreads_will_payloadat packet-build time, both checked against 2.1.0 — so_on_connectre-arms it. That bounds the staleness by the reconnect interval, a few hours here, rather than by the process lifetime, which for a long-lived agent would have meant the will still describing boot weeks later.device_seen_atrides along regardless, so even the frozen-within-a-session case is labelled rather than misleading.Two related deliberate choices, also noted in review:
_disconnected()keepserrorandmedia_okrather than clearing them. A consumer switching onstatealone would miss a latched fault; that is the correct trade here, because the alternative is a disconnect notice that forgets the printer had no tape. The InvenTree driver renders from the whole payload.probe_devicestampsseen_atafter the settle sleep, so it can read up to a second late. The replies arrive during that window, so the error is bounded by the settle and immaterial at the resolution this field is published in (whole seconds).The window the will leaves open, and what closes it
Raised on the consumer PR, and it is a real residual rather than a hypothetical.
A fault learned during a session cannot reach that session's will — the broker holds it from CONNECT. So: agent connects while the tape is fine, a print an hour later finds the tape gone and correctly publishes
error/media_ok: false, the agent is then killed, and the broker publishes the older healthier reading over the newer one. The topic goes backwards, which is the same shape as the bug this PR fixes.Prevention is not available. Re-arming on reconnect (above) bounds it by the reconnect interval instead of the process lifetime, but cannot touch a live session.
on_disconnectcannot help either — it fires with no connection to publish on — and a SIGKILL runs no callback at all.What bounds it is recovery. The unit is
Restart=always/RestartSec=5, and a restarted agent seeds_last_statusfrom the spool — which does hold the fault, because_capture_feedbackpersists before the crash — and republishes it on connect. The stale-healthy row is therefore seconds wide, not indefinite, and it is markedDISCONNECTEDthroughout.That property was carrying the whole argument while being untested, so
test_a_stale_will_is_corrected_by_the_restart_that_follows_itnow asserts it end to end: arm a healthy will, learn a fault mid-session, restart on the same spool, and check the republished status carries the fault and adevice_seen_atstrictly newer than the will's.Documented on the consumer side too, since that is where it is visible.