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.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This commit is contained in:
2026-10-03 10:12:05 +00:00
co-authored by Claude Opus 5
parent 704b65ac26
commit 1d95451c4c
8 changed files with 1698 additions and 37 deletions
+156 -33
View File
@@ -32,10 +32,69 @@ pub struct PrintReport {
pub tray_is_bbl_bits: Option<String>,
pub xcam: Option<XcamSettings>,
pub xcam_status: Option<String>,
// The real payload has a lot more fields than shown here (this
// example was truncated) - add them the same way, one field per line,
// `Option<T>` for anything that isn't always present. Remember to
// also add each new field to `merge_from` below.
// --- Job progress. The reason this struct exists at all, for a print
// --- farm: a real capture has 97 top-level fields and the nine above
// --- contained none of the ones an operator actually wants.
/// `"IDLE"`, `"RUNNING"`, `"PAUSE"`, `"FINISH"`, `"FAILED"` - observed
/// `IDLE` on an idle P1P and `RUNNING` mid-print on an H2C. Treated as a
/// string rather than an enum deliberately: an unknown state should show
/// up as itself, not fail the whole report.
pub gcode_state: Option<String>,
/// Percent complete, 0-100. v2 also sends an identical `percent`.
pub mc_percent: Option<i32>,
/// Minutes remaining. v2 also sends an identical `remain_time`.
pub mc_remaining_time: Option<i32>,
pub layer_num: Option<i32>,
pub total_layer_num: Option<i32>,
/// Path on the printer, e.g. `/data/Metadata/plate_1.gcode`.
pub gcode_file: Option<String>,
/// The human-facing job name, e.g. a model filename.
pub subtask_name: Option<String>,
/// `0` when nothing is wrong.
pub print_error: Option<i32>,
// --- Temperatures. `f32` throughout, not `i32`: v1 reports an idle
// --- target as the integer `0` while v2 reports `35.0`, and serde
// --- widens an integer into a float but not the reverse.
pub nozzle_temper: Option<f32>,
pub nozzle_target_temper: Option<f32>,
pub bed_temper: Option<f32>,
pub bed_target_temper: Option<f32>,
/// Not sent by every model - absent from the H2C capture.
pub chamber_temper: Option<f32>,
// --- Fans and connectivity.
/// Fan speeds come back as *strings* holding a **0-15 gear**, not a
/// percentage and not the 0-255 PWM value `set_fan_speed` sends. All
/// three scales are in play at once, so converting carelessly gives a
/// number that looks plausible and is wrong:
///
/// - we send PWM 0-255 (`M106 S<pwm>`, see `percent_to_pwm`),
/// - the operator thinks in percent 0-100,
/// - the printer reports gear 0-15.
///
/// Confirmed live on a P1P: a full-speed heatbreak fan reads `"15"`, and
/// `set_fan_speed(50)` (PWM 127) read back as `"7"`. Divide by 15 for a
/// fraction, not by 100 and not by 255.
pub cooling_fan_speed: Option<String>,
pub heatbreak_fan_speed: Option<String>,
pub big_fan1_speed: Option<String>,
pub big_fan2_speed: Option<String>,
pub wifi_signal: Option<String>,
/// Health-management-system entries - the printer's own error/warning
/// list, empty when healthy. Left as raw JSON for now: an H2C mid-print
/// reported several `{attr, code}` pairs whose meaning needs decoding
/// against Bambu's HMS tables before it's worth a typed shape.
pub hms: Option<Vec<serde_json::Value>>,
// There are still ~60 more top-level fields in a real v2 payload (see
// `tests/fixtures/push_status_v2_h2c_printing.json` for the full set):
// the `job`/`device`/`net`/`upload` sub-objects, queue state, the
// `2D`/`3D` blocks, and so on. Add them the same way - one field per
// line, `Option<T>` unless it was seen on every capture from both
// generations. `merge_from` below needs no edit when you do.
}
impl PrintReport {
@@ -45,33 +104,55 @@ impl PrintReport {
/// existing value alone instead of clobbering it. Not used for v2
/// (always a full object) or for a `pushall`-triggered reply on
/// either version (also guaranteed full) - see `BambuMqttSession`.
/// Every field below is the same one-liner:
/// `self.x = newer.x.or(self.x.take())`. `Option::or` returns the first
/// `Option` if it's `Some` and the second otherwise, so this reads as
/// "prefer the new value, fall back to what we had" - exactly the merge
/// rule, in the place a TS version would write `newer.x ?? self.x`.
/// `take()` is what makes it work for a `String`/`Vec` field too: it
/// moves the old value out and leaves `None` behind, since the value
/// can't be copied out of `self` and we're overwriting it anyway.
///
/// This replaced two dozen four-line `if newer.x.is_some()` blocks. The
/// point isn't brevity for its own sake - it's that the old shape made
/// adding a field a three-place edit (struct, merge, and remembering to),
/// and forgetting the merge half produced a field that silently never
/// persisted across a partial update.
pub fn merge_from(&mut self, newer: PrintReport) {
self.envelope = newer.envelope;
self.msg = newer.msg;
if newer.ams.is_some() {
self.ams = newer.ams;
}
if newer.ams_exist_bits.is_some() {
self.ams_exist_bits = newer.ams_exist_bits;
}
if newer.insert_flag.is_some() {
self.insert_flag = newer.insert_flag;
}
if newer.power_on_flag.is_some() {
self.power_on_flag = newer.power_on_flag;
}
if newer.tray_exist_bits.is_some() {
self.tray_exist_bits = newer.tray_exist_bits;
}
if newer.tray_is_bbl_bits.is_some() {
self.tray_is_bbl_bits = newer.tray_is_bbl_bits;
}
if newer.xcam.is_some() {
self.xcam = newer.xcam;
}
if newer.xcam_status.is_some() {
self.xcam_status = newer.xcam_status;
}
self.ams = newer.ams.or(self.ams.take());
self.ams_exist_bits = newer.ams_exist_bits.or(self.ams_exist_bits.take());
self.insert_flag = newer.insert_flag.or(self.insert_flag.take());
self.power_on_flag = newer.power_on_flag.or(self.power_on_flag.take());
self.tray_exist_bits = newer.tray_exist_bits.or(self.tray_exist_bits.take());
self.tray_is_bbl_bits = newer.tray_is_bbl_bits.or(self.tray_is_bbl_bits.take());
self.xcam = newer.xcam.or(self.xcam.take());
self.xcam_status = newer.xcam_status.or(self.xcam_status.take());
self.gcode_state = newer.gcode_state.or(self.gcode_state.take());
self.mc_percent = newer.mc_percent.or(self.mc_percent.take());
self.mc_remaining_time = newer.mc_remaining_time.or(self.mc_remaining_time.take());
self.layer_num = newer.layer_num.or(self.layer_num.take());
self.total_layer_num = newer.total_layer_num.or(self.total_layer_num.take());
self.gcode_file = newer.gcode_file.or(self.gcode_file.take());
self.subtask_name = newer.subtask_name.or(self.subtask_name.take());
self.print_error = newer.print_error.or(self.print_error.take());
self.nozzle_temper = newer.nozzle_temper.or(self.nozzle_temper.take());
self.nozzle_target_temper = newer.nozzle_target_temper.or(self.nozzle_target_temper.take());
self.bed_temper = newer.bed_temper.or(self.bed_temper.take());
self.bed_target_temper = newer.bed_target_temper.or(self.bed_target_temper.take());
self.chamber_temper = newer.chamber_temper.or(self.chamber_temper.take());
self.cooling_fan_speed = newer.cooling_fan_speed.or(self.cooling_fan_speed.take());
self.heatbreak_fan_speed = newer.heatbreak_fan_speed.or(self.heatbreak_fan_speed.take());
self.big_fan1_speed = newer.big_fan1_speed.or(self.big_fan1_speed.take());
self.big_fan2_speed = newer.big_fan2_speed.or(self.big_fan2_speed.take());
self.wifi_signal = newer.wifi_signal.or(self.wifi_signal.take());
self.hms = newer.hms.or(self.hms.take());
}
}
@@ -83,13 +164,19 @@ pub struct AmsState {
pub ams: Vec<AmsUnit>,
}
/// One physical AMS unit (Bambu's numbering starts at 0 via `id`).
/// One physical AMS unit (Bambu's numbering starts at 0 via `id`). Only
/// `id` and `tray` were present on every unit across both captures, so the
/// rest are optional - an H2C reports three units of different kinds
/// (`n3f`/`n3s`) and they don't all carry the same fields.
#[derive(serde::Deserialize, Debug, Clone)]
pub struct AmsUnit {
pub humidity: String,
pub id: String,
pub temp: String,
pub tray: Vec<AmsTray>,
pub humidity: Option<String>,
pub temp: Option<String>,
pub humidity_raw: Option<String>,
pub dry_time: Option<i32>,
pub info: Option<String>,
}
/// A tray slot is either empty (just `id`) or loaded (the full field set)
@@ -107,20 +194,47 @@ pub enum AmsTray {
Loaded(LoadedTray),
}
/// `deny_unknown_fields` stays - it's what stops a *loaded* tray (23 fields,
/// a superset of this one) matching `Empty` first. But an empty slot is not
/// always just `{"id": "..."}`: an H2C reports `{"id": "2", "state": 0}` on
/// an empty slot, and that two-field shape matched neither variant, which
/// failed the entire report (and so every `push_status` the printer sent
/// while an AMS slot was empty). Captured in
/// `tests/fixtures/push_status_v2_h2c_printing.json`.
///
/// Anything genuinely new here will fail loudly rather than be quietly
/// dropped, which is the point of keeping `deny_unknown_fields`: better a
/// visible error naming the field than a report that silently vanishes.
#[derive(serde::Deserialize, Debug, Clone)]
#[serde(deny_unknown_fields)]
pub struct EmptyTray {
pub id: String,
/// v2 sends this on an empty slot; v1 omits it entirely.
pub state: Option<i32>,
}
/// Captured from both generations (see `tests/push_status_parsing.rs`), and
/// they do **not** agree. A v2 tray carries `drying_temp`/`drying_time`; a
/// v1 tray carries `tray_temp`/`tray_time` and neither `drying_*` field.
/// Every one of these was `String` (required) before, which meant every
/// single v1 push carrying AMS data failed to deserialize - silently, so it
/// looked like the printer simply wasn't sending anything. All four are
/// `Option` now, and so is anything else only one generation was observed
/// to send.
#[derive(serde::Deserialize, Debug, Clone)]
pub struct LoadedTray {
pub id: String,
pub bed_temp: String,
pub bed_temp_type: String,
pub cols: Vec<String>,
pub drying_temp: String,
pub drying_time: String,
/// v2 only.
pub drying_temp: Option<String>,
/// v2 only.
pub drying_time: Option<String>,
/// v1 only - the same idea as `drying_temp` under a different name.
pub tray_temp: Option<String>,
/// v1 only - the same idea as `drying_time` under a different name.
pub tray_time: Option<String>,
pub nozzle_temp_max: String,
pub nozzle_temp_min: String,
pub remain: i32,
@@ -134,6 +248,15 @@ pub struct LoadedTray {
pub tray_uuid: String,
pub tray_weight: String,
pub xcam_info: String,
/// Seen on both, but not in the original truncated example this struct
/// was built from.
pub state: Option<i32>,
pub cali_idx: Option<i32>,
pub ctype: Option<i32>,
pub total_len: Option<i64>,
/// Flow-calibration coefficients - v1 sends these on a loaded tray.
pub k: Option<f32>,
pub n: Option<i32>,
}
/// Camera-based AI print monitoring settings (spaghetti detection,
+45 -4
View File
@@ -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("?")
),
}
}