Skip to content

fix(agent): stop reconnects and restarts erasing device truth from the status topic - #13

Merged
impuls42 merged 3 commits into
mainfrom
fix/status-remembers-device-truth
Aug 2, 2026
Merged

fix(agent): stop reconnects and restarts erasing device truth from the status topic#13
impuls42 merged 3 commits into
mainfrom
fix/status-remembers-device-truth

Conversation

@impuls42

@impuls42 impuls42 commented Aug 2, 2026

Copy link
Copy Markdown
Member

Closes #12.

What was happening

Two causes behind one symptom, and the one in the issue comment is the one that actually bites.

_on_connect published a hardcoded bare PrinterStatus, 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 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.

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_at is new on PrinterStatus. Remembered truth published as though it were live is its own kind of lie — the same failure the tri-state media_ok exists 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.json is generated from PrintJob only, 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_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, 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.mac now 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 + MqttSource up on the same DB, fire _on_connect:

what the retained topic holds after the restart:
 "serial": "Q223P4C31420105", "firmware": "2.1.2", "battery_pct": 100,
 "voltage_v": 4.17, "media_ok": true, "device_seen_at": "..."

after a reconnect, serial is still: Q223P4C31420105

InvenTree renders: ('CONNECTED', 'fw 2.1.2 · 100% (4.17V) · media ok · Q223P4C31420105')

against CONNECTED — media unreported today.

tests/test_source_mqtt.py is 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.md was 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_set has no connected-state guard and _send_connect reads _will_payload at packet-build time, both checked against 2.1.0 — so _on_connect re-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_at rides along regardless, so even the frozen-within-a-session case is labelled rather than misleading.

Two related deliberate choices, also noted in review:

  • _disconnected() keeps error and media_ok rather than clearing them. A consumer switching on state alone 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_device stamps seen_at after 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_disconnect cannot 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_status from the spool — which does hold the fault, because _capture_feedback persists before the crash — and republishes it on connect. The stale-healthy row is therefore seconds wide, not indefinite, and it is marked DISCONNECTED throughout.

That property was carrying the whole argument while being untested, so test_a_stale_will_is_corrected_by_the_restart_that_follows_it now 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 a device_seen_at strictly newer than the will's.

Documented on the consumer side too, since that is where it is visible.

…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
@impuls42

impuls42 commented Aug 2, 2026

Copy link
Copy Markdown
Member Author

Consumer half is up: sengine-cloud/inventree-label-dispatch#7 renders device_seen_at as · seen 6h ago on the Machines page, so remembered truth is not shown as live there either.

@impuls42

impuls42 commented Aug 2, 2026

Copy link
Copy Markdown
Member Author

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 _will_* fields on every automatic reconnect — will_set has no connected-state guard, and _send_connect reads _will_payload at packet-build time, both checked against 2.1.0. So _on_connect now re-arms it (09c6487). That moves the staleness bound from the process lifetime — which for a long-lived agent meant the will still describing boot weeks later — down to the reconnect interval, a few hours here. Armed from paho's network thread, the same thread that builds the packet, so topic and payload can't come from different passes.

The residual constraint is in the PR description now, along with the two cosmetics: _disconnected() deliberately keeps error/media_ok (a disconnect notice that forgets the printer had no tape is worse than one a state-only consumer under-reads), and probe_device's ≤1s late seen_at is bounded by the settle window and below the whole-second resolution the field publishes at.

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.
impuls42 added a commit to sengine-cloud/inventree-label-dispatch that referenced this pull request Aug 2, 2026
…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.
@impuls42
impuls42 merged commit 2a94945 into main Aug 2, 2026
1 check passed
@impuls42
impuls42 deleted the fix/status-remembers-device-truth branch August 2, 2026 14:46
impuls42 added a commit that referenced this pull request Aug 2, 2026
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).
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

After an agent restart the status topic carries no device truth until the first print

1 participant