continuum-proxy/examples/bambu_print_probe.rs

//! Run with: cargo run --example bambu_print_probe -- <printer-id> <step> [arg]
//!
//! Probes the print-start and print-control commands against a real printer,
//! one deliberate step at a time. **Some of these steps commit a physical
//! machine to work**, so nothing here happens implicitly: every step is named
//! on the command line, and the ones that can start a print additionally
//! require `--yes-start-a-real-print`.
//!
//! Steps, in the order worth running them:
//!
//! - `status`            read-only. Connect, print state, list `cache/`.
//! - `probe-missing`     **zero physical risk.** Sends `print.gcode_file`
//!   pointing at a file that does not exist. The printer
//!   cannot start anything, so this isolates one
//!   question: does it accept and parse the command shape
//!   at all? A clean rejection naming the file means the
//!   shape is right and only the target was wrong. A
//!   parse error, or silence, means the shape is wrong.
//! - `upload <local> [name]`
//!   **inert.** FTPS-transfers a local file onto the card
//!   and stops - nothing prints until told to. Reports
//!   the byte count the printer accepted and the rate.
//! - `delete <path>`      removes one named file from the card.
//! - `blink`              runs `completion::celebrate`, the real ten-second
//!   finished-print blink, and then checks the light
//!   ended off. Twenty light commands in ten seconds is
//!   a rate the printer may refuse, which is the thing
//!   this answers.
//! - `light on|off|flash`
//!   **no physical risk** beyond a light changing. `on`
//!   and `off` go through `BambuPrinter::set_light`, the
//!   same call `completion::run` blinks with, so this
//!   confirms the shipped path rather than a hand-built
//!   body. `flash` instead sends the schema's `flashing`
//!   mode raw, to settle what `loop_times` and
//!   `interval_time` actually do - the self-driven blink
//!   exists because that was unconfirmed.
//! - `start <file>`      sends `print.gcode_file`/`print.project_file` for a
//!   file in `cache/`. Gated on `gcode_state: IDLE` and
//!   on the explicit flag.
//! - `pause` / `resume` / `stop`
//!   the control commands. `stop` cancels - it is the
//!   undo for `start`, and the reason `start` is worth
//!   testing at all: without it a cloud-initiated print
//!   could only be ended at the machine.
//!
//! After whatever it sends, it watches the `print.push_status` stream and
//! reports every change to the fields that matter. Run with
//! `RUST_LOG=continuum_proxy::printer::bambu_mqtt=trace` to see the raw
//! payloads too - which is where a rejection that `PrintReport` does not
//! model will show up.

use std::time::Duration;

use continuum_proxy::fleet;
use continuum_proxy::printer::{
    FilamentSource, GenericPrinter, LightState, PrintControl, PrinterHandle, CHAMBER_LIGHT,
};

const CONNECT_TIMEOUT: Duration = Duration::from_secs(20);
const STATUS_TIMEOUT: Duration = Duration::from_secs(15);
/// How long to watch the report stream after sending something.
const WATCH: Duration = Duration::from_secs(20);
/// How long to wait for a light change to show up in `lights_report`. A v1
/// printer only reports when asked, so this polls `pushall` rather than
/// waiting on an organic push that is not coming.
const LIGHT_READBACK: Duration = Duration::from_secs(12);
/// Only for the message - `completion.rs` owns the real value.
const BLINK_FOR_DISPLAY: &str = "10s";

/// A file name that cannot exist in `cache/`, for `probe-missing`.
const MISSING_FILE: &str = "continuum-probe-no-such-file.gcode";

/// Every tray a P1P with one AMS has: 4 AMS slots plus the external spool.
/// `ams_mapping` has to be padded to this length - see the schema.
const P1P_TRAY_COUNT: usize = 5;

#[tokio::main]
async fn main() -> anyhow::Result<()> {
    // Without this there is no subscriber, so the `trace!` of every raw
    // report in bambu_mqtt.rs goes nowhere and RUST_LOG appears to do
    // nothing - which is exactly how the first run of this probe came back
    // with no evidence either way.
    tracing_subscriber::fmt()
        .with_env_filter(
            tracing_subscriber::EnvFilter::try_from_default_env()
                .unwrap_or_else(|_| tracing_subscriber::EnvFilter::new("info")),
        )
        .init();

    let args: Vec<String> = std::env::args().collect();
    let (Some(target), Some(step)) = (args.get(1).cloned(), args.get(2).cloned()) else {
        anyhow::bail!(
            "usage: cargo run --example bambu_print_probe -- <printer-id> <step> [arg]\n\
             steps: status | probe-missing | light on|off|flash | start <file-in-cache> \
             | pause | resume | stop"
        );
    };
    let confirmed = args.iter().any(|a| a == "--yes-start-a-real-print");

    // Handled before the fleet below is borrowed, because the real blink
    // wants the whole fleet behind a lock rather than one printer.
    if step == "blink" {
        return blink_probe(&target).await;
    }

    let mut printers = fleet::load(std::path::Path::new("printers.toml"))?;
    let printer = printers
        .iter_mut()
        .find(|p| p.base().id == target)
        .ok_or_else(|| anyhow::anyhow!("no printer with id '{target}' in printers.toml"))?;

    let PrinterHandle::Bambu(bambu) = printer else {
        anyhow::bail!("'{target}' is not a Bambu printer - this example is Bambu-specific");
    };

    println!("=== {} / step: {step} ===", bambu.display_name());

    match tokio::time::timeout(CONNECT_TIMEOUT, bambu.connect()).await {
        Ok(Ok(())) => {}
        Ok(Err(err)) => anyhow::bail!("connect failed: {err}"),
        Err(_) => anyhow::bail!("connect timed out - printer off or unreachable?"),
    }

    // v1 answers only when asked; v2 pushes unprompted.
    bambu.pushall().await.ok();
    let state = wait_for_state(bambu).await?;
    println!("  state before: {state}");

    match step.as_str() {
        "status" => {
            match bambu.list_cache().await {
                Ok(entries) => {
                    println!("\n  cache/ ({} entries):", entries.len());
                    for entry in &entries {
                        println!("    {entry}");
                    }
                }
                Err(err) => println!("  cache list FAILED: {err}"),
            }
            return Ok(());
        }

        "probe-missing" => {
            // Cannot start anything: the file is not there. This asks only
            // whether the command shape is understood.
            println!("\n  sending print.gcode_file for a file that does not exist:");
            println!("    param -> /cache/{MISSING_FILE}");
            match bambu
                .start_uploaded_file(MISSING_FILE, &FilamentSource::ExternalSpool)
                .await
            {
                Ok(()) => println!("    the printer ACCEPTED it (result: success)"),
                Err(err) => anyhow::bail!("the printer answered: {err}"),
            }
        }

        "start" => {
            let Some(file) = args.get(3).filter(|a| !a.starts_with("--")).cloned() else {
                anyhow::bail!("`start` needs a file name that is already in cache/ - run `status` to list them");
            };
            // The guard's job is "don't start a print on a machine that may
            // already be working", and IDLE is not the only state that
            // satisfies it. FINISH and FAILED are both terminal - FAILED is
            // what a Bambu reports after an operator cancellation, so
            // demanding IDLE made the harness refuse every print following a
            // cancelled one, which is the normal case when testing. PREPARE,
            // RUNNING, PAUSE and SLICING all mean the machine is committed,
            // and anything unrecognised is refused rather than assumed idle.
            const READY_TO_START: [&str; 3] = ["IDLE", "FINISH", "FAILED"];
            if !READY_TO_START.contains(&state.as_str()) {
                anyhow::bail!(
                    "printer reports '{state}', which is not one of {READY_TO_START:?} - \
                     refusing to start a print on a machine that may already be working"
                );
            }
            if !confirmed {
                anyhow::bail!(
                    "refusing to start a real print without --yes-start-a-real-print.\n\
                     This commits the machine to physical work. Be at the printer."
                );
            }
            // `--ams=3` or `--ams=3,-1,0` picks AMS slots per project
            // filament index; without it, the external spool. There is no
            // default that is safe for both, so the flag has to be explicit.
            let filament = match args.iter().find_map(|a| a.strip_prefix("--ams=")) {
                Some(list) => {
                    let slots = list
                        .split(',')
                        .map(|slot| slot.trim().parse::<i32>())
                        .collect::<Result<Vec<_>, _>>()
                        .map_err(|err| anyhow::anyhow!("--ams needs a comma-separated list of slot numbers: {err}"))?;
                    // 4 AMS slots + 1 external spool on a P1P with one AMS.
                    // See the padding rule in the ams_mapping schema.
                    FilamentSource::ams(slots, P1P_TRAY_COUNT)
                        .map_err(|err| anyhow::anyhow!("{err}"))?
                }
                None => FilamentSource::ExternalSpool,
            };
            match &filament {
                FilamentSource::ExternalSpool => {
                    println!("\n  starting print of '{file}' from the EXTERNAL SPOOL ...")
                }
                FilamentSource::Ams(slots) => {
                    println!("\n  starting print of '{file}' with ams_mapping {slots:?} ...")
                }
            }
            match bambu.start_uploaded_file(&file, &filament).await {
                Ok(()) => println!("    accepted"),
                Err(err) => anyhow::bail!("the printer answered: {err}"),
            }
        }

        "pause" | "resume" | "stop" => {
            let action = match step.as_str() {
                "pause" => PrintControl::Pause,
                "resume" => PrintControl::Resume,
                _ => PrintControl::Stop,
            };
            println!("\n  sending print.{} ...", action.as_str());
            match bambu.control_print(action).await {
                Ok(()) => println!("    accepted"),
                Err(err) => anyhow::bail!("the printer answered: {err}"),
            }
        }

        // `light on|off|flash`. The first two deliberately go through
        // `set_light` rather than a raw body: that method had never once
        // reached a printer, and `completion::run` blinks a finished print's
        // chamber light with it, so the thing worth testing is it and not a
        // body written here to match.
        "light" => {
            let mode = args.get(3).map(String::as_str).unwrap_or("on");
            match mode {
                "on" | "off" => {
                    let state = if mode == "on" { LightState::On } else { LightState::Off };
                    println!("\n  set_light({CHAMBER_LIGHT}, {mode}):");
                    match bambu.set_light(CHAMBER_LIGHT, state).await {
                        Ok(()) => println!("    accepted"),
                        Err(err) => println!("    FAILED: {err}"),
                    }
                    // "Accepted" is not "it changed" - a ledctrl reply says
                    // success as soon as the command parses. `lights_report`
                    // is the only read-back there is, so poll until the
                    // printer says the light is what we asked for.
                    report_light(bambu, mode).await;
                }
                // Raw, because there is no typed call for it yet - that is
                // the point of the probe. Deliberately short: 3 cycles of
                // 500ms on / 500ms off, matching what `completion::run`
                // drives by hand, so the two are comparable by eye.
                "flash" => {
                    let body = serde_json::json!({
                        "command": "ledctrl",
                        "led_node": CHAMBER_LIGHT,
                        "led_mode": "flashing",
                        "led_on_time": 500,
                        "led_off_time": 500,
                        "loop_times": 3,
                        "interval_time": 1000,
                    });
                    println!("\n  sending system.ledctrl flashing (3x 500/500, interval 1000):");
                    match bambu.request_raw("system", body).await {
                        Ok(reply) => println!("    reply: {reply}"),
                        Err(err) => println!("    no usable reply: {err}"),
                    }
                    println!(
                        "    watch the printer: 3 blinks means loop_times is cycles; \n\
                         anything else means the field means something other than that"
                    );
                    // And read it back, which says whether `flashing` is a
                    // firmware *mode* the printer holds and reports, or a
                    // one-shot that leaves the reported mode untouched.
                    report_light(bambu, "flashing").await;
                }
                other => anyhow::bail!("`light` takes on, off or flash - not '{other}'"),
            }
            return Ok(());
        }

        // `shape <json>` sends one `print` command verbatim as a correlated
        // request and prints the reply. For settling an unconfirmed command
        // shape against the hardware - see `BambuPrinter::request_raw`.
        "shape" => {
            let Some(raw) = args.get(3) else {
                anyhow::bail!("`shape` needs a JSON body for the `print` category");
            };
            let body: serde_json::Value = serde_json::from_str(raw)
                .map_err(|err| anyhow::anyhow!("that is not valid JSON: {err}"))?;
            println!("\n  sending print {} ...", body["command"]);
            match bambu.request_raw("print", body).await {
                Ok(reply) => println!("    reply: {reply}"),
                Err(err) => println!("    no usable reply: {err}"),
            }
        }

        // `upload <local> [name]` puts a file on the card and stops there.
        // Inert: a file on the SD card does nothing until something is told
        // to print it. The only proven transfer before this was 102 bytes,
        // and real projects on the card run to 62 MB - a size at which
        // buffering, timeouts and the FTPS data connection all start to
        // matter in ways a 102-byte write cannot show.
        "upload" => {
            let Some(local) = args.get(3) else {
                anyhow::bail!("`upload` needs a local file path");
            };
            let data = std::fs::read(local)?;
            let name = args
                .get(4)
                .cloned()
                .unwrap_or_else(|| format!("continuum-probe-{}", file_stem(local)));
            println!("\n  uploading {} bytes as {name} ...", data.len());
            let started = std::time::Instant::now();
            match bambu.upload_file(&name, data.clone()).await {
                Ok(written) => {
                    let elapsed = started.elapsed();
                    println!("    printer accepted {written} bytes in {elapsed:?}");
                    if written == data.len() as u64 {
                        let rate = data.len() as f64 / elapsed.as_secs_f64() / 1_048_576.0;
                        println!("    byte count matches exactly ({rate:.1} MiB/s)");
                    } else {
                        println!("    MISMATCH: sent {}, printer took {written}", data.len());
                    }
                }
                Err(err) => println!("    upload FAILED: {err}"),
            }
            return Ok(());
        }

        // `delete <path>` removes one file. Named in full on the command
        // line every time - there is no pattern form on purpose.
        "delete" => {
            let Some(path) = args.get(3) else {
                anyhow::bail!("`delete` needs the exact path of a file on the card");
            };
            println!("\n  deleting {path} ...");
            match bambu.delete_file(path).await {
                Ok(()) => println!("    gone"),
                Err(err) => println!("    delete FAILED: {err}"),
            }
            return Ok(());
        }

        // `fetch <path> <dest>` copies one file off the card. Read-only.
        "fetch" => {
            let (Some(path), Some(dest)) = (args.get(3), args.get(4)) else {
                anyhow::bail!("`fetch` needs a path on the printer and a local destination");
            };
            match bambu.download_file(path).await {
                Ok(bytes) => {
                    std::fs::write(dest, &bytes)?;
                    println!("    {} bytes -> {dest}", bytes.len());
                }
                Err(err) => anyhow::bail!("fetch failed: {err}"),
            }
        }

        other => anyhow::bail!("unknown step '{other}'"),
    }

    watch(bambu, state).await;
    Ok(())
}

/// The file name without its directory, for naming an upload after its
/// source. Not `Path::file_stem`, which would strip only the last extension
/// and turn `tray.stl.gcode.3mf` into something that is no longer a `.3mf`.
fn file_stem(path: &str) -> String {
    path.rsplit('/').next().unwrap_or(path).to_string()
}

/// Runs `completion::celebrate` - the actual ten-second blink a finished print
/// triggers - against a real printer. The question it answers is a rate one:
/// `celebrate` sends twenty `ledctrl` commands half a second apart, and a
/// printer is entitled to refuse that. It stops at the first failure, so if
/// the rate is too high this prints one warning and ends dark.
async fn blink_probe(target: &str) -> anyhow::Result<()> {
    use std::sync::Arc;
    use tokio::sync::Mutex;

    let mut printers = fleet::load(std::path::Path::new("printers.toml"))?;
    {
        let printer = printers
            .iter_mut()
            .find(|p| p.base().id == target)
            .ok_or_else(|| anyhow::anyhow!("no printer with id '{target}' in printers.toml"))?;
        let PrinterHandle::Bambu(bambu) = printer else {
            anyhow::bail!("'{target}' is not a Bambu printer");
        };
        println!("=== {} / step: blink ===", bambu.display_name());
        match tokio::time::timeout(CONNECT_TIMEOUT, bambu.connect()).await {
            Ok(Ok(())) => {}
            Ok(Err(err)) => anyhow::bail!("connect failed: {err}"),
            Err(_) => anyhow::bail!("connect timed out - printer off or unreachable?"),
        }
    }

    println!("\n  running completion::celebrate for {BLINK_FOR_DISPLAY} - watch the printer");
    let fleet: continuum_proxy::uplink::SharedFleet = Arc::new(Mutex::new(printers));
    let started = std::time::Instant::now();
    continuum_proxy::completion::celebrate(fleet.clone(), target.to_string()).await;
    println!("  returned after {:?}", started.elapsed());

    // It is specified to end dark, which is the part worth checking: a blink
    // that leaves the light on looks like a printer that is still busy.
    let fleet = fleet.lock().await;
    if let Some(PrinterHandle::Bambu(bambu)) = fleet.iter().find(|p| p.base().id == target) {
        report_light(bambu, "off").await;
    }
    Ok(())
}

/// Polls `lights_report` until the chamber light reads `want`, printing every
/// change with the time it took. Gives up rather than hanging: a light that
/// never reports what was asked for is the result, not a reason to wait.
async fn report_light(bambu: &continuum_proxy::printer::BambuPrinter, want: &str) {
    let started = std::time::Instant::now();
    let mut last = String::new();
    while started.elapsed() < LIGHT_READBACK {
        let mode = bambu
            .print_status()
            .await
            .and_then(|r| r.lights_report)
            .and_then(|lights| {
                lights
                    .into_iter()
                    .find(|l| l.node.as_deref() == Some(CHAMBER_LIGHT))
                    .and_then(|l| l.mode)
            });
        let mode = mode.unwrap_or_else(|| "<not reported>".into());
        if mode != last {
            println!("    lights_report after {:?}: {CHAMBER_LIGHT} = {mode}", started.elapsed());
            last = mode.clone();
        }
        if mode == want {
            println!("    confirmed: the printer reports '{want}', not just that it accepted it");
            return;
        }
        bambu.pushall().await.ok();
        tokio::time::sleep(Duration::from_millis(1500)).await;
    }
    println!("    gave up after {LIGHT_READBACK:?}: last reported '{last}', asked for '{want}'");
}

async fn wait_for_state(bambu: &continuum_proxy::printer::BambuPrinter) -> anyhow::Result<String> {
    let deadline = tokio::time::Instant::now() + STATUS_TIMEOUT;
    loop {
        if let Some(report) = bambu.print_status().await
            && let Some(state) = report.gcode_state.clone()
        {
            return Ok(state);
        }
        if tokio::time::Instant::now() >= deadline {
            anyhow::bail!(
                "no print.push_status with a gcode_state within {STATUS_TIMEOUT:?} - refusing to \
                 go further, because there is no way to tell what this printer is doing"
            );
        }
        tokio::time::sleep(Duration::from_millis(500)).await;
    }
}

/// Reports every change to the fields that would show a command landing.
async fn watch(bambu: &continuum_proxy::printer::BambuPrinter, before: String) {
    println!("\n  watching the report stream for {WATCH:?} ...");
    let deadline = tokio::time::Instant::now() + WATCH;
    let mut last = before;
    let mut last_error: Option<i32> = None;
    let mut last_task = String::new();

    while tokio::time::Instant::now() < deadline {
        // v1 needs asking each time for a complete object.
        bambu.pushall().await.ok();
        tokio::time::sleep(Duration::from_millis(1500)).await;

        if let Some(report) = bambu.print_status().await {
            if let Some(state) = report.gcode_state.clone()
                && state != last
            {
                println!("    gcode_state: {last} -> {state}");
                last = state;
            }
            if report.print_error != last_error {
                println!("    print_error: {:?} -> {:?}", last_error, report.print_error);
                last_error = report.print_error;
            }
            let task = report.subtask_name.clone().unwrap_or_default();
            if task != last_task {
                println!("    subtask_name: '{last_task}' -> '{task}'");
                last_task = task;
            }
            if let Some(hms) = &report.hms
                && !hms.is_empty()
            {
                println!("    hms (printer alerts): {}", serde_json::to_string(hms).unwrap_or_default());
            }
        }
    }
    println!("  final state: {last}");
}