Fix print.push_status parsing, and stop losing reports silently
Pointed at a real H2C that was 20% into a job, `print_status()` returned
nothing at all. The printer was in fact pushing a full status object every
second; every one was arriving, failing to deserialize, and being dropped
invisibly by an `if let Ok(report) = ..` with no `else`.
That silence produced two confidently-wrong claims in our own comments,
both corrected here:
- `pushall`'s doc said whether v2 emits `push_status` unprompted was "an
open question". It is not: v2 pushes a full 97-field object roughly once
a second from the moment you subscribe, no trigger needed. There is no
missing "other trigger" to hunt for.
- The "sequence gap" warning blamed the network for dropped v1 updates.
Those updates were not dropped in transit - they failed to parse, so
they never reached the counter, making the next one that did look like a
skip. Confirmed: seq 57, 62, 64 and 69 all arrived. After the fix, zero
gaps and zero parse failures across a 25s run against both printers.
Two concrete causes, both found with captured payloads:
- v1 trays carry `tray_temp`/`tray_time`; v2 trays carry
`drying_temp`/`drying_time`. All four were required, so *every* v1 push
carrying AMS data failed.
- A third tray shape existed that nothing modelled: an empty v2 slot sends
`{"id": "2", "state": 0}`, which matched neither `EmptyTray` (it denies
unknown fields, deliberately) nor `LoadedTray` (16 fields short).
A parse failure now reports itself, naming the printer, the sequence id and
the serde error. A report this process cannot parse is a defect in
`PrintReport`, and the only way to fix it is to be told which field.
`PrintReport` itself modelled 9 of 97 top-level fields, and none of them
were progress or temperature - it was built from a truncated example. It
now carries gcode_state, percent, layer counts, remaining time, nozzle/bed
temperatures, fan gears, wifi and HMS entries. `merge_from`'s two dozen
four-line blocks collapse to `newer.x.or(self.x.take())` one-liners: the
old shape made adding a field a three-place edit, and forgetting the merge
half produced a field that silently never survived a partial update.
Two scale traps documented where they bite: reported fan speeds are 0-15
gears, not percent and not the 0-255 PWM we send (`set_fan_speed(50)`
reads back as "7"); and v2 pins `sequence_id` to one value for minutes
while contents change, so it orders and identifies nothing there.
Two examples, and the distinction between them is the point. `live_reports`
is read-only and safe against a printer mid-job. `bambu_idle_checks`
writes, so it requires an explicit printer id and refuses to run unless
that printer reports `gcode_state: "IDLE"`.
Regression fixtures are verbatim captures off both printers, hardware
identifiers scrubbed - the only way to keep this from regressing without a
printer plugged in.
This commit is contained in:
@@ -121,6 +121,15 @@ enum BambuMqttClient {
|
||||
/// timing worked out; `msg` needs none of that: it's on the message
|
||||
/// itself, correct regardless of which client (or nothing at all)
|
||||
/// triggered it, and regardless of timing.
|
||||
/// - **v2 does not use `sequence_id` as a counter here at all.** Confirmed
|
||||
/// live against an H2C mid-print on 2026-10-03: every organic
|
||||
/// `push_status` carried the *same* `sequence_id` (`"2021"`) for minutes
|
||||
/// on end while the contents (percent, layer, remaining time) changed
|
||||
/// normally. So on v2 it identifies nothing and orders nothing - don't
|
||||
/// use it to detect staleness or to deduplicate. The gap check below
|
||||
/// already skips v2 (every v2 message is a full object), which turns out
|
||||
/// to be necessary rather than merely tidy: it would otherwise warn on
|
||||
/// every single message.
|
||||
/// - `last_sequence_id` exists to notice when v1's organic stream skipped
|
||||
/// an update (network hiccup, a message this client wasn't fast enough
|
||||
/// to read): if the incoming `sequence_id` isn't exactly one more than
|
||||
@@ -147,6 +156,12 @@ impl PrintStatusCache {
|
||||
// full) isn't a real problem worth warning about.
|
||||
let is_full_object = matches!(version, BambuProtocolVersion::V2) || incoming.msg != Some(1);
|
||||
|
||||
// Only reachable for v1 partial updates. Historically this fired
|
||||
// constantly and blamed the network, when the real cause was local:
|
||||
// a push that failed to deserialize never reached this function, so
|
||||
// the next one that did looked like it had skipped ahead. That is now
|
||||
// reported where it happens (see `handle_incoming_report`), which
|
||||
// leaves this warning meaning what it says.
|
||||
if let (Some(last), Some(incoming_seq), false) = (self.last_sequence_id, incoming_seq, is_full_object) {
|
||||
if incoming_seq != last.wrapping_add(1) {
|
||||
eprintln!(
|
||||
@@ -388,7 +403,7 @@ async fn poll_loop_v1(
|
||||
loop {
|
||||
match event_loop.poll().await {
|
||||
Ok(Event::Incoming(Packet::Publish(publish))) => {
|
||||
handle_incoming_report(&pending, &print_status, version, &publish.payload).await;
|
||||
handle_incoming_report(&sn, &pending, &print_status, version, &publish.payload).await;
|
||||
}
|
||||
Ok(_) => {}
|
||||
Err(err) => {
|
||||
@@ -409,7 +424,7 @@ async fn poll_loop_v2(
|
||||
loop {
|
||||
match event_loop.poll().await {
|
||||
Ok(rumqttc::v5::Event::Incoming(PacketV5::Publish(publish))) => {
|
||||
handle_incoming_report(&pending, &print_status, version, &publish.payload).await;
|
||||
handle_incoming_report(&sn, &pending, &print_status, version, &publish.payload).await;
|
||||
}
|
||||
Ok(_) => {}
|
||||
Err(err) => {
|
||||
@@ -444,11 +459,21 @@ async fn poll_loop_v2(
|
||||
/// (including every organic `push_status` push) aren't a reply to
|
||||
/// anything specific.
|
||||
async fn handle_incoming_report(
|
||||
sn: &str,
|
||||
pending: &PendingTable,
|
||||
print_status: &Arc<Mutex<PrintStatusCache>>,
|
||||
version: BambuProtocolVersion,
|
||||
payload: &[u8],
|
||||
) {
|
||||
// The raw bytes, before anything gets parsed or thrown away. `PrintReport`
|
||||
// deliberately models only a fraction of what a real `push_status`
|
||||
// carries (see its doc comment), so without this the rest is
|
||||
// unrecoverable - you can't add a field to that struct if you can never
|
||||
// see what the printer actually sent. At `trace` so it costs nothing
|
||||
// normally; turn it on with
|
||||
// `RUST_LOG=continuum_proxy::printer::bambu_mqtt=trace`.
|
||||
tracing::trace!(target: "continuum_proxy::printer::bambu_mqtt", sn, raw = %String::from_utf8_lossy(payload), "incoming report");
|
||||
|
||||
let Ok(value) = serde_json::from_slice::<Value>(payload) else { return };
|
||||
let Some(object) = value.as_object() else { return };
|
||||
let Some((category, body)) = object.iter().next() else { return };
|
||||
@@ -459,8 +484,24 @@ async fn handle_incoming_report(
|
||||
};
|
||||
|
||||
if category == "print" && body.get("command").and_then(Value::as_str) == Some("push_status") {
|
||||
if let Ok(report) = serde_json::from_value::<PrintReport>(body.clone()) {
|
||||
print_status.lock().await.apply(report, version);
|
||||
match serde_json::from_value::<PrintReport>(body.clone()) {
|
||||
Ok(report) => print_status.lock().await.apply(report, version),
|
||||
// Loudly, not silently. This arm used to be an `if let Ok(..)`
|
||||
// with no `else`, and it cost two misdiagnosed symptoms on real
|
||||
// hardware: `print_status()` stayed `None` forever on an H2C
|
||||
// that was in fact pushing a full report every second (read as
|
||||
// "v2 doesn't push unprompted", which was wrong), and every v1
|
||||
// push carrying AMS data vanished - which the gap check below
|
||||
// then reported as a *sequence gap*, blaming the network for a
|
||||
// local deserialization bug. A report this process can't parse
|
||||
// is a real defect in `PrintReport`, and the only way to fix it
|
||||
// is to be told which field.
|
||||
Err(err) => eprintln!(
|
||||
"[{sn}] print.push_status (sequence_id {}) did not match PrintReport, dropping it: \
|
||||
{err} - add the field to PrintReport and a fixture to \
|
||||
tests/push_status_parsing.rs",
|
||||
body.get("sequence_id").and_then(Value::as_str).unwrap_or("?")
|
||||
),
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
Reference in New Issue
Block a user